Added request tracing

[justinpolygon]

A new optional trace parameter in RequestOption enables request and response logging for debugging. When activated via models.WithTrace(true) on the request, the requested URL, sanitized request headers, and response headers are printed to the console.

Here's an example script:

package main

import (
    "context"
    "log"
    "os"
    "time"
    "fmt"

    polygon "github.com/polygon-io/client-go/rest"
    "github.com/polygon-io/client-go/rest/models"
)

func main() {

    // init client
    c := polygon.New(os.Getenv("POLYGON_API_KEY"))

    // set params
    params := models.ListAggsParams{
        Ticker:     "AAPL",
        Multiplier: 1,
        Timespan:   "minute",
        From:       models.Millis(time.Date(2022, 1, 1, 0, 0, 0, 0, time.UTC)),
        To:         models.Millis(time.Date(2023, 6, 14, 0, 0, 0, 0, time.UTC)),
    }.WithOrder(models.Desc).WithLimit(50000).WithAdjusted(true)

    var count int64

    // make request
    iter := c.ListAggs(context.Background(), params, models.WithTrace(true))

    // do something with the result
    for iter.Next() {
        //log.Print(iter.Item())
        count++
    }
    if iter.Err() != nil {
        log.Fatal(iter.Err())
    }

    fmt.Println(count)

}

The output looks like this:

go run main.go
Request URL: /v2/aggs/ticker/AAPL/range/1/minute/1640995200000/1686700800000?adjusted=true&limit=50000&sort=desc
Request Headers: map[Accept-Encoding:[gzip] Authorization:[REDACTED] User-Agent:[Polygon.io GoClient/v1.11.0]]
Response Headers: map[Content-Encoding:[gzip] Content-Type:[application/json] Date:[Fri, 16 Jun 2023 16:51:17 GMT] Server:[nginx/1.19.2] Strict-Transport-Security:[max-age=15724800; includeSubDomains] Vary:[Accept-Encoding] X-Request-Id:[415a486ea6db0dc513b8cd5410f50a13]]
Request URL: https://api.polygon.io/v2/aggs/ticker/AAPL/range/1/minute/1640995200000/1678393019999?cursor=bGltaXQ9NTAwMDAmc29ydD1kZXNj
Request Headers: map[Accept-Encoding:[gzip] Authorization:[REDACTED] User-Agent:[Polygon.io GoClient/v1.11.0]]
Response Headers: map[Content-Encoding:[gzip] Content-Type:[application/json] Date:[Fri, 16 Jun 2023 16:51:18 GMT] Server:[nginx/1.19.2] Strict-Transport-Security:[max-age=15724800; includeSubDomains] Vary:[Accept-Encoding] X-Request-Id:[f09d612c43f730c94bc9306a02a4f7aa]]
Request URL: https://api.polygon.io/v2/aggs/ticker/AAPL/range/1/minute/1640995200000/1670354219999?cursor=bGltaXQ9NTAwMDAmc29ydD1kZXNj
Request Headers: map[Accept-Encoding:[gzip] Authorization:[REDACTED] User-Agent:[Polygon.io GoClient/v1.11.0]]
Response Headers: map[Content-Encoding:[gzip] Content-Type:[application/json] Date:[Fri, 16 Jun 2023 16:51:19 GMT] Server:[nginx/1.19.2] Strict-Transport-Security:[max-age=15724800; includeSubDomains] Vary:[Accept-Encoding] X-Request-Id:[6fa0ec5a65368624cf7afb8df970fc2a]]
Request URL: https://api.polygon.io/v2/aggs/ticker/AAPL/range/1/minute/1640995200000/1662746159999?cursor=bGltaXQ9NTAwMDAmc29ydD1kZXNj
Request Headers: map[Accept-Encoding:[gzip] Authorization:[REDACTED] User-Agent:[Polygon.io GoClient/v1.11.0]]
Response Headers: map[Content-Encoding:[gzip] Content-Type:[application/json] Date:[Fri, 16 Jun 2023 16:51:20 GMT] Server:[nginx/1.19.2] Strict-Transport-Security:[max-age=15724800; includeSubDomains] Vary:[Accept-Encoding] X-Request-Id:[dd52e655b9293ec193581f2d411a0062]]
Request URL: https://api.polygon.io/v2/aggs/ticker/AAPL/range/1/minute/1640995200000/1654813499999?cursor=bGltaXQ9NTAwMDAmc29ydD1kZXNj
Request Headers: map[Accept-Encoding:[gzip] Authorization:[REDACTED] User-Agent:[Polygon.io GoClient/v1.11.0]]
Response Headers: map[Content-Encoding:[gzip] Content-Type:[application/json] Date:[Fri, 16 Jun 2023 16:51:21 GMT] Server:[nginx/1.19.2] Strict-Transport-Security:[max-age=15724800; includeSubDomains] Vary:[Accept-Encoding] X-Request-Id:[06ec6ca2536152caddc9e2281a1cee86]]
Request URL: https://api.polygon.io/v2/aggs/ticker/AAPL/range/1/minute/1640995200000/1647341939999?cursor=bGltaXQ9NTAwMDAmc29ydD1kZXNj
Request Headers: map[Accept-Encoding:[gzip] Authorization:[REDACTED] User-Agent:[Polygon.io GoClient/v1.11.0]]
Response Headers: map[Content-Encoding:[gzip] Content-Type:[application/json] Date:[Fri, 16 Jun 2023 16:51:22 GMT] Server:[nginx/1.19.2] Strict-Transport-Security:[max-age=15724800; includeSubDomains] Vary:[Accept-Encoding] X-Request-Id:[f0dee9f19981ca93efc465bf97e5865c]]
291150

Dumping the request url, request headers, and response headers can be extremely useful for figuring out what API you're talking, the params, and what server headers are (the x-request-id is really useful for support).

[justinpolygon]

@jbonzo, that would have saved me some time. I'll check that out.

[jbonzo]

@jbonzo, that would have saved me some time. I'll check that out.

Just gotta check that it sanitizes the info.

[justinpolygon]

Hey @jbonzo, checked this out and looks like you turn it on via req.EnableTrace() and it is mostly connection information, things like tcp connection time, dns lookup, tls connection times, etc. Here's the trace.go file, and the docs this can either be turned on at the client or request level. They do have a very nice example though. So, I replicated the formatting and incorporated the trace info from Rust.

Here's what the new output looks like after running the example script:

go run main.go
Request Info:
  DNSLookup     : 22.91075ms
  ConnTime      : 212.144542ms
  TCPConnTime   : 85.698167ms
  TLSHandshake  : 102.899167ms
  ServerTime    : 218.900458ms
  ResponseTime  : 76.948875ms
  TotalTime     : 507.640333ms
  IsConnReused  : false
  IsConnWasIdle : false
  ConnIdleTime  : 0s
  RequestAttempt: 1
  RemoteAddr    : 198.44.194.54:443
  Request URL   : GET /v2/aggs/ticker/AAPL/range/1/minute/1686614400000/1686700800000?adjusted=true&limit=50000&sort=desc

Request Headers:
  Accept-Encoding: [gzip]
  Authorization: [REDACTED]
  User-Agent: [Polygon.io GoClient/v1.11.0]

Response Info:
  Error      : <nil>
  Status Code: 200
  Status     : 200 OK
  Proto      : HTTP/2.0
  Time       : 507.640333ms
  Received At: 2023-06-16 11:19:39.954729 -0700 PDT m=+0.514939459

Response Headers:
  Date: [Fri, 16 Jun 2023 18:19:39 GMT]
  Content-Type: [application/json]
  Content-Encoding: [gzip]
  Vary: [Accept-Encoding]
  X-Request-Id: [48cf36ce2ab5a88e3383a97e72c596bb]
  Strict-Transport-Security: [max-age=15724800; includeSubDomains]
  Server: [nginx/1.19.2]

808

[jbonzo]

Gothca. Since we expose the underlying HTTP client then I think users can already access this functionality, though it might not be clear. I am fine to go ahead and merge this PR if you think your proposal is more in line with user's interest, but maybe adding to our docs that you can access the underlying HTTP client tracing could also satisfy the needs.

[justinpolygon]

@jbonzo Yeah, this makes sense. Honestly, I just wanted to simplify our lives in terms of developing features for the client libraries. I added this feature on the python and js libraries and it as come in so handy when you're trying to debug what's happening behind the scenes (for example using filter params like ticker.gt, ticker.gte, ticker.lt, and ticker.lte or when using ticker.any_of). Having something that shows you what's happening under the hood really helped me squash these bugs and acts as a sanity check to prove you're sending the API what you think you are sending. Just being able to quickly add models.WithTrace(true) to the request and not having you roll your own solution comes in pretty handy.

[jbonzo]

Sounds good. Ping me when you reverted back the test code and ill review again.

[justinpolygon]

FYI @jbonzo -- I think we're good to go now. Thanks for your help and feedback here.