Skip to content

Commit

Permalink
added tracing (#83)
Browse files Browse the repository at this point in the history
  • Loading branch information
bzimmer authored Jan 26, 2023
1 parent 288c484 commit 383123c
Show file tree
Hide file tree
Showing 8 changed files with 157 additions and 57 deletions.
130 changes: 130 additions & 0 deletions cmd/ma/clienttrace.go
Original file line number Diff line number Diff line change
@@ -0,0 +1,130 @@
package main

import (
"crypto/tls"
"net/http/httptrace"
"net/textproto"

"github.com/rs/zerolog/log"
)

func ClientTrace() *httptrace.ClientTrace { //nolint:funlen
return &httptrace.ClientTrace{
// GetConn is called before a connection is created or
// retrieved from an idle pool. The hostPort is the
// "host:port" of the target or proxy. GetConn is called even
// if there's already an idle cached connection available.
GetConn: func(hostPort string) {
log.Info().Str("hostport", hostPort).Msg("GetConn")
},

// GotConn is called after a successful connection is
// obtained. There is no hook for failure to obtain a
// connection; instead, use the error from
// Transport.RoundTrip.
GotConn: func(info httptrace.GotConnInfo) {
log.Info().Interface("info", info).Msg("GotConn")
},

// PutIdleConn is called when the connection is returned to
// the idle pool. If err is nil, the connection was
// successfully returned to the idle pool. If err is non-nil,
// it describes why not. PutIdleConn is not called if
// connection reuse is disabled via Transport.DisableKeepAlives.
// PutIdleConn is called before the caller's Response.Body.Close
// call returns.
// For HTTP/2, this hook is not currently used.
PutIdleConn: func(err error) {
log.Info().Err(err).Msg("PutIdleConn")
},

// GotFirstResponseByte is called when the first byte of the response
// headers is available.
GotFirstResponseByte: func() {
log.Info().Msg("GotFirstResponseByte")
},

// Got100Continue is called if the server replies with a "100
// Continue" response.
Got100Continue: func() {
log.Info().Msg("Got100Continue")
},

// Got1xxResponse is called for each 1xx informational response header
// returned before the final non-1xx response. Got1xxResponse is called
// for "100 Continue" responses, even if Got100Continue is also defined.
// If it returns an error, the client request is aborted with that error value.
Got1xxResponse: func(code int, header textproto.MIMEHeader) error {
log.Info().Int("code", code).Msg("Got1xxResponse")
return nil
},

// DNSStart is called when a DNS lookup begins.
DNSStart: func(info httptrace.DNSStartInfo) {
log.Info().Interface("info", info).Msg("DNSStart")
},

// DNSDone is called when a DNS lookup ends.
DNSDone: func(info httptrace.DNSDoneInfo) {
log.Info().Interface("info", info).Msg("DNSDone")
},

// ConnectStart is called when a new connection's Dial begins.
// If net.Dialer.DualStack (IPv6 "Happy Eyeballs") support is
// enabled, this may be called multiple times.
ConnectStart: func(network, addr string) {
log.Info().Str("network", network).Str("addr", addr).Msg("ConnectStart")
},

// ConnectDone is called when a new connection's Dial
// completes. The provided err indicates whether the
// connection completed successfully.
// If net.Dialer.DualStack ("Happy Eyeballs") support is
// enabled, this may be called multiple times.
ConnectDone: func(network, addr string, err error) {
log.Info().Str("network", network).Str("addr", addr).Msg("ConnectDone")
},

// TLSHandshakeStart is called when the TLS handshake is started. When
// connecting to an HTTPS site via an HTTP proxy, the handshake happens
// after the CONNECT request is processed by the proxy.
TLSHandshakeStart: func() {
log.Info().Msg("TLSHandshakeStart")
},

// TLSHandshakeDone is called after the TLS handshake with either the
// successful handshake's connection state, or a non-nil error on handshake
// failure.
TLSHandshakeDone: func(_ tls.ConnectionState, _ error) {
log.Info().Msg("TLSHandshakeDone")
},

// WroteHeaderField is called after the Transport has written
// each request header. At the time of this call the values
// might be buffered and not yet written to the network.
WroteHeaderField: func(key string, value []string) {
log.Info().Str("key", key).Strs("value", value).Msg("WroteHeaderField")
},

// WroteHeaders is called after the Transport has written
// all request headers.
WroteHeaders: func() {
log.Info().Msg("WroteHeaders")
},

// Wait100Continue is called if the Request specified
// "Expect: 100-continue" and the Transport has written the
// request headers but is waiting for "100 Continue" from the
// server before writing the request body.
Wait100Continue: func() {
log.Info().Msg("Wait100Continue")
},

// WroteRequest is called with the result of writing the
// request and any body. It may be called multiple times
// in the case of retried requests.
WroteRequest: func(info httptrace.WroteRequestInfo) {
log.Info().Msg("WroteRequest")
},
}
}
27 changes: 19 additions & 8 deletions cmd/ma/main.go
Original file line number Diff line number Diff line change
Expand Up @@ -3,7 +3,9 @@ package main
import (
"context"
"encoding/json"
"io"
"net/http"
"net/http/httptrace"
"os"
"time"

Expand Down Expand Up @@ -67,6 +69,13 @@ func flags() []cli.Flag {
Usage: "enable debugging of http requests",
Value: false,
},
&cli.BoolFlag{
Name: "trace",
Required: false,
Usage: "enable http client tracing",
Value: false,
Hidden: true,
},
}
}

Expand Down Expand Up @@ -139,12 +148,9 @@ func main() {
return err
}

var enc ma.Encoder
switch {
case c.Bool("json"):
enc = ma.NewJSONEncoder(json.NewEncoder(c.App.Writer))
default:
enc = ma.NewBlackholeEncoder()
writer := io.Discard
if c.Bool("json") {
writer = c.App.Writer
}

c.App.Metadata = map[string]any{
Expand All @@ -153,14 +159,18 @@ func main() {
Sink: sink,
Grab: grab,
Metrics: metric,
Encoder: enc,
Encoder: json.NewEncoder(writer),
Fs: afero.NewOsFs(),
Exif: ma.NewGoExif(),
Language: language.English,
Start: time.Now(),
},
}

if c.Bool("trace") {
c.Context = httptrace.WithClientTrace(c.Context, ClientTrace())
}

return nil
},
After: ma.Metrics,
Expand All @@ -184,7 +194,8 @@ func main() {
manual.Manual(),
},
}
if err := app.RunContext(context.Background(), os.Args); err != nil {
ctx := context.Background()
if err := app.RunContext(ctx, os.Args); err != nil {
os.Exit(1)
}
os.Exit(0)
Expand Down
3 changes: 2 additions & 1 deletion docs/manual.md
Original file line number Diff line number Diff line change
Expand Up @@ -10,9 +10,9 @@ All your media archiving needs!
|```smugmug-access-token```||smugmug access token|
|```smugmug-token-secret```||smugmug token secret|
|```json```|```j```|emit all results as JSON and print to stdout|
|```metrics```||emit summary metrics (requires --json) in addition to operation data|
|```monochrome```||disable colored output|
|```debug```||enable debugging of http requests|
|```trace```||enable http client tracing|
|```help```|```h```|show help|

## Commands
Expand Down Expand Up @@ -537,6 +537,7 @@ $ ma up [flags]
|```ext```|```x```||the set of file extensions suitable for uploading|
|```dryrun```|```n```||prepare to upload but don't actually do it|
|```mirror```|||mirror the local filesystem with a SmugMug gallery|
|```0```|||read null byte terminated strings from stdin|

**Example**

Expand Down
16 changes: 0 additions & 16 deletions go.sum
Original file line number Diff line number Diff line change
Expand Up @@ -54,8 +54,6 @@ github.com/bzimmer/httpwares v0.1.0 h1:ZaMJ51JXKNqJRsx1vtgQGVa7Qz3yZJOzvyhGrQYEP
github.com/bzimmer/httpwares v0.1.0/go.mod h1:d7haVrcuMW9I+4Ha/V54JtyqGbu0raahd0NqqQSr2p0=
github.com/bzimmer/manual v0.1.0 h1:bwjezUGB2iKK0kDUHYIb5IzA4+iR/UNDoBrhZ0+ijW4=
github.com/bzimmer/manual v0.1.0/go.mod h1:RftaUkPvNcdXbGj2u3qtXDOeBvJgInJLs3lCjnTknks=
github.com/bzimmer/smugmug v0.7.0 h1:cpX10YFTaDarNUIBKks9VgR5uEb0NtNnb1v10D9QUSI=
github.com/bzimmer/smugmug v0.7.0/go.mod h1:FtGyvRCUpFfEnnR6mpn/qOudFw8Z3dC5I/ycjigpgWs=
github.com/bzimmer/smugmug v0.7.1 h1:lh9et9U74vTfqWfHYSqDNzzBypzF3PwDd9szhAagOIo=
github.com/bzimmer/smugmug v0.7.1/go.mod h1:lEtdp42SE+qNZ2m52alMZUZrIyQu/Md4g2E3o0T9Ttg=
github.com/census-instrumentation/opencensus-proto v0.2.1/go.mod h1:f6KPmirojxKA12rnyqOA5BBL4O983OfeGPqjHWSTneU=
Expand Down Expand Up @@ -222,21 +220,13 @@ github.com/spf13/afero v1.9.3 h1:41FoI0fD7OR7mGcKE/aOiLkGreyf8ifIOQmJANWogMk=
github.com/spf13/afero v1.9.3/go.mod h1:iUV7ddyEEZPO5gA3zD4fJt6iStLlL+Lg4m2cihcDf8Y=
github.com/stretchr/objx v0.1.0/go.mod h1:HFkY916IF+rwdDfMAkV7OtwuqBVzrE8GR6GFx+wExME=
github.com/stretchr/objx v0.1.1/go.mod h1:HFkY916IF+rwdDfMAkV7OtwuqBVzrE8GR6GFx+wExME=
github.com/stretchr/objx v0.4.0/go.mod h1:YvHI0jy2hoMjB+UWwv71VJQ9isScKT/TqJzVSSt89Yw=
github.com/stretchr/objx v0.5.0/go.mod h1:Yh+to48EsGEfYuaHDzXPcE3xhTkx73EhmCGUpEOglKo=
github.com/stretchr/testify v1.2.2/go.mod h1:a8OnRcib4nhh0OaRAV+Yts87kKdq0PP7pXfy6kDkUVs=
github.com/stretchr/testify v1.3.0/go.mod h1:M5WIy9Dh21IEIfnGCwXGc5bZfKNJtfHm1UVUgZn+9EI=
github.com/stretchr/testify v1.4.0/go.mod h1:j7eGeouHqKxXV5pUuKE4zz7dFj8WfuZ+81PSLYec5m4=
github.com/stretchr/testify v1.5.1/go.mod h1:5W2xD1RspED5o8YsWQXVCued0rvSQ+mT+I5cxcmMvtA=
github.com/stretchr/testify v1.7.0 h1:nwc3DEeHmmLAfoZucVR881uASk0Mfjw8xYJ99tb5CcY=
github.com/stretchr/testify v1.7.0/go.mod h1:6Fq8oRcR53rry900zMqJjRRixrwX3KX962/h/Wwjteg=
github.com/stretchr/testify v1.7.1/go.mod h1:6Fq8oRcR53rry900zMqJjRRixrwX3KX962/h/Wwjteg=
github.com/stretchr/testify v1.8.0/go.mod h1:yNjHg4UonilssWZ8iaSj1OCr/vHnekPRkoO+kdMU+MU=
github.com/stretchr/testify v1.8.1 h1:w7B6lhMri9wdJUVmEZPGGhZzrYTPvgJArz7wNPgYKsk=
github.com/stretchr/testify v1.8.1/go.mod h1:w2LPCIKwWwSfY2zedu0+kehJoqGctiVI29o6fzry7u4=
github.com/tv42/httpunix v0.0.0-20150427012821-b75d8614f926/go.mod h1:9ESjWnEqriFuLhtthL60Sar/7RFoluCcXsuvEwTV5KM=
github.com/urfave/cli/v2 v2.23.5 h1:xbrU7tAYviSpqeR3X4nEFWUdB/uDZ6DE+HxmRU7Xtyw=
github.com/urfave/cli/v2 v2.23.5/go.mod h1:GHupkWPMM0M/sj1a2b4wUrWBPzazNrIjouW6fmdJLxc=
github.com/urfave/cli/v2 v2.23.7 h1:YHDQ46s3VghFHFf1DdF+Sh7H4RqhcM+t0TmZRJx4oJY=
github.com/urfave/cli/v2 v2.23.7/go.mod h1:GHupkWPMM0M/sj1a2b4wUrWBPzazNrIjouW6fmdJLxc=
github.com/vitali-fedulov/hyper v1.0.1/go.mod h1:nQqkBaCL7ETNg7c90cbfFeJWoKchMrPejZYr+kiuSQI=
Expand Down Expand Up @@ -391,8 +381,6 @@ golang.org/x/sys v0.0.0-20210615035016-665e8c7367d1/go.mod h1:oPkhp1MJrh7nUepCBc
golang.org/x/sys v0.0.0-20210630005230-0f9fa26af87c/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg=
golang.org/x/sys v0.0.0-20210927094055-39ccf1dd6fa6/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg=
golang.org/x/sys v0.0.0-20220811171246-fbc7d0a398ab/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg=
golang.org/x/sys v0.2.0 h1:ljd4t30dBnAvMZaQCevtY0xLLD0A+bRZXbgLMLU1F/A=
golang.org/x/sys v0.2.0/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg=
golang.org/x/sys v0.3.0 h1:w8ZOecv6NaNa/zC8944JTU3vz4u6Lagfk4RPQxv92NQ=
golang.org/x/sys v0.3.0/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg=
golang.org/x/term v0.0.0-20201126162022-7de9c90e9dd1/go.mod h1:bj7SfCRtBDWHUb9snDiAeCFNEtKQo2Wmx5Cou7ajbmo=
Expand All @@ -402,15 +390,11 @@ golang.org/x/text v0.3.1-0.20180807135948-17ff2d5776d2/go.mod h1:NqM8EUOU14njkJ3
golang.org/x/text v0.3.2/go.mod h1:bEr9sfX3Q8Zfm5fL9x+3itogRgK3+ptLWKqgva+5dAk=
golang.org/x/text v0.3.3/go.mod h1:5Zoc/QRtKVWzQhOtBMvqHzDpF6irO9z98xDceosuGiQ=
golang.org/x/text v0.3.4/go.mod h1:5Zoc/QRtKVWzQhOtBMvqHzDpF6irO9z98xDceosuGiQ=
golang.org/x/text v0.4.0 h1:BrVqGRd7+k1DiOgtnFvAkoQEWQvBc25ouMJM6429SFg=
golang.org/x/text v0.4.0/go.mod h1:mrYo+phRRbMaCq/xk9113O4dZlRixOauAjOtrjsXDZ8=
golang.org/x/text v0.5.0 h1:OLmvp0KP+FVG99Ct/qFiL/Fhk4zp4QQnZ7b2U+5piUM=
golang.org/x/text v0.5.0/go.mod h1:mrYo+phRRbMaCq/xk9113O4dZlRixOauAjOtrjsXDZ8=
golang.org/x/time v0.0.0-20181108054448-85acf8d2951c/go.mod h1:tRJNPiyCQ0inRvYxbN9jk5I+vvW/OXSQhTDSoE431IQ=
golang.org/x/time v0.0.0-20190308202827-9d24e82272b4/go.mod h1:tRJNPiyCQ0inRvYxbN9jk5I+vvW/OXSQhTDSoE431IQ=
golang.org/x/time v0.0.0-20191024005414-555d28b269f0/go.mod h1:tRJNPiyCQ0inRvYxbN9jk5I+vvW/OXSQhTDSoE431IQ=
golang.org/x/time v0.2.0 h1:52I/1L54xyEQAYdtcSuxtiT84KGYTBGXwayxmIpNJhE=
golang.org/x/time v0.2.0/go.mod h1:tRJNPiyCQ0inRvYxbN9jk5I+vvW/OXSQhTDSoE431IQ=
golang.org/x/time v0.3.0 h1:rg5rLMjNzMS1RkNLzCG38eapWhnYLFYXDXj2gOlr8j4=
golang.org/x/time v0.3.0/go.mod h1:tRJNPiyCQ0inRvYxbN9jk5I+vvW/OXSQhTDSoE431IQ=
golang.org/x/tools v0.0.0-20180917221912-90fa682c2a6e/go.mod h1:n7NCudcB/nEzxVGmLbDWY5pfWTLqBcC2KZ6jyYvM4mQ=
Expand Down
11 changes: 4 additions & 7 deletions ma_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -89,19 +89,16 @@ func NewTestApp(t *testing.T, tt *harness, cmd *cli.Command, url string) *cli.Ap
t.Error(err)
}

var enc ma.Encoder
switch {
case c.Bool("json"):
enc = ma.NewJSONEncoder(json.NewEncoder(c.App.Writer))
default:
enc = ma.NewBlackholeEncoder()
writer := io.Discard
if c.Bool("json") {
writer = c.App.Writer
}

rt := &ma.Runtime{
Client: client,
Metrics: metric,
Sink: sink,
Encoder: enc,
Encoder: json.NewEncoder(writer),
Grab: new(http.Client),
Fs: afero.NewMemMapFs(),
Exif: ma.NewGoExif(),
Expand Down
23 changes: 0 additions & 23 deletions runtime.go
Original file line number Diff line number Diff line change
@@ -1,7 +1,6 @@
package ma

import (
"encoding/json"
"fmt"
"regexp"
"time"
Expand Down Expand Up @@ -46,28 +45,6 @@ type Encoder interface {
Encode(v any) error
}

type encoderBlackhole struct{}

func (e *encoderBlackhole) Encode(_ any) error {
return nil
}

func NewBlackholeEncoder() Encoder {
return &encoderBlackhole{}
}

type encoderJSON struct {
encoder *json.Encoder
}

func (e *encoderJSON) Encode(v any) error {
return e.encoder.Encode(v)
}

func NewJSONEncoder(enc *json.Encoder) Encoder {
return &encoderJSON{encoder: enc}
}

func runtime(c *cli.Context) *Runtime {
return c.App.Metadata[RuntimeKey].(*Runtime)
}
Expand Down
2 changes: 1 addition & 1 deletion title_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -17,7 +17,7 @@ func TestTitle(t *testing.T) {

before := func(c *cli.Context) error {
c.App.Writer = new(bytes.Buffer)
runtime(c).Encoder = ma.NewJSONEncoder(json.NewEncoder(c.App.Writer))
runtime(c).Encoder = json.NewEncoder(c.App.Writer)
return nil
}
after := func(u string) cli.AfterFunc {
Expand Down
2 changes: 1 addition & 1 deletion urlname_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -17,7 +17,7 @@ func TestURLName(t *testing.T) {

before := func(c *cli.Context) error {
c.App.Writer = new(bytes.Buffer)
runtime(c).Encoder = ma.NewJSONEncoder(json.NewEncoder(c.App.Writer))
runtime(c).Encoder = json.NewEncoder(c.App.Writer)
return nil
}
after := func(u string, valid bool) cli.AfterFunc {
Expand Down

0 comments on commit 383123c

Please sign in to comment.