Skip to content

Commit

Permalink
Expand logging support for HTTP traffic (#60)
Browse files Browse the repository at this point in the history
- Respect the GH_DEBUG environment variable by default, but add the option to skip it;
- Add option to opt into colorized logging;
- Add option to explicitly log HTTP headers and bodies—the new default is off;
- Colorize JSON payloads when logging HTTP bodies;
- Log form-encoded payloads;
- Pretty-print GraphQL queries when logging HTTP requests.

Co-authored-by: Sam Coe <samcoe@users.noreply.github.com>
  • Loading branch information
mislav and samcoe committed Aug 10, 2022
1 parent f649e37 commit d7a6f56
Show file tree
Hide file tree
Showing 8 changed files with 341 additions and 21 deletions.
14 changes: 8 additions & 6 deletions internal/api/cache_test.go
Expand Up @@ -34,9 +34,10 @@ func TestCacheResponse(t *testing.T) {

httpClient := NewHTTPClient(
&api.ClientOptions{
Transport: fakeHTTP,
EnableCache: true,
CacheDir: cacheDir,
Transport: fakeHTTP,
EnableCache: true,
CacheDir: cacheDir,
LogIgnoreEnv: true,
})

do := func(method, url string, body io.Reader) (string, error) {
Expand Down Expand Up @@ -114,9 +115,10 @@ func TestCacheResponseRequestCacheOptions(t *testing.T) {

httpClient := NewHTTPClient(
&api.ClientOptions{
Transport: fakeHTTP,
EnableCache: false,
CacheDir: cacheDir,
Transport: fakeHTTP,
EnableCache: false,
CacheDir: cacheDir,
LogIgnoreEnv: true,
})

do := func(method, url string, body io.Reader) (string, error) {
Expand Down
31 changes: 23 additions & 8 deletions internal/api/http.go
Expand Up @@ -12,6 +12,7 @@ import (
"time"

"github.com/cli/go-gh/pkg/api"
"github.com/cli/go-gh/pkg/term"
"github.com/henvic/httpretty"
"github.com/thlib/go-timezone-local/tzlocal"
)
Expand Down Expand Up @@ -54,17 +55,29 @@ func NewHTTPClient(opts *api.ClientOptions) http.Client {
c := cache{dir: opts.CacheDir, ttl: opts.CacheTTL}
transport = c.RoundTripper(transport)

if opts.Log == nil && !opts.LogIgnoreEnv {
ghDebug := os.Getenv("GH_DEBUG")
switch ghDebug {
case "", "0", "false", "no":
// no logging
default:
opts.Log = os.Stderr
opts.LogColorize = !term.IsColorDisabled() && term.IsTerminal(os.Stderr)
opts.LogVerboseHTTP = strings.Contains(ghDebug, "api")
}
}

if opts.Log != nil {
logger := &httpretty.Logger{
Time: true,
TLS: false,
Colors: false,
RequestHeader: true,
RequestBody: true,
ResponseHeader: true,
ResponseBody: true,
Formatters: []httpretty.Formatter{&httpretty.JSONFormatter{}},
MaxResponseBody: 10000,
Colors: opts.LogColorize,
RequestHeader: opts.LogVerboseHTTP,
RequestBody: opts.LogVerboseHTTP,
ResponseHeader: opts.LogVerboseHTTP,
ResponseBody: opts.LogVerboseHTTP,
Formatters: []httpretty.Formatter{&jsonFormatter{colorize: opts.LogColorize}},
MaxResponseBody: 100000,
}
logger.SetOutput(opts.Log)
logger.SetBodyFilter(func(h http.Header) (skip bool, err error) {
Expand All @@ -85,7 +98,9 @@ func NewHTTPClient(opts *api.ClientOptions) http.Client {
}

func inspectableMIMEType(t string) bool {
return strings.HasPrefix(t, "text/") || jsonTypeRE.MatchString(t)
return strings.HasPrefix(t, "text/") ||
strings.HasPrefix(t, "application/x-www-form-urlencoded") ||
jsonTypeRE.MatchString(t)
}

func isSameDomain(requestHost, domain string) bool {
Expand Down
1 change: 1 addition & 0 deletions internal/api/http_test.go
Expand Up @@ -120,6 +120,7 @@ func TestNewHTTPClient(t *testing.T) {
Headers: tt.headers,
SkipDefaultHeaders: tt.skipHeaders,
Transport: reflectHTTP,
LogIgnoreEnv: true,
}
if tt.enableLog {
opts.Log = tt.log
Expand Down
47 changes: 47 additions & 0 deletions internal/api/log_formatter.go
@@ -0,0 +1,47 @@
package api

import (
"bytes"
"encoding/json"
"fmt"
"io"
"strings"

"github.com/cli/go-gh/pkg/jsonpretty"
)

type graphqlBody struct {
Query string `json:"query"`
OperationName string `json:"operationName"`
Variables json.RawMessage `json:"variables"`
}

// jsonFormatter is a httpretty.Formatter that prettifies JSON payloads and GraphQL queries.
type jsonFormatter struct {
colorize bool
}

func (f *jsonFormatter) Format(w io.Writer, src []byte) error {
var graphqlQuery graphqlBody
// TODO: find more precise way to detect a GraphQL query from the JSON payload alone
if err := json.Unmarshal(src, &graphqlQuery); err == nil && graphqlQuery.Query != "" && len(graphqlQuery.Variables) > 0 {
colorHighlight := "\x1b[35;1m"
colorReset := "\x1b[m"
if !f.colorize {
colorHighlight = ""
colorReset = ""
}
if _, err := fmt.Fprintf(w, "%sGraphQL query:%s\n%s\n", colorHighlight, colorReset, strings.ReplaceAll(strings.TrimSpace(graphqlQuery.Query), "\t", " ")); err != nil {
return err
}
if _, err := fmt.Fprintf(w, "%sGraphQL variables:%s %s\n", colorHighlight, colorReset, string(graphqlQuery.Variables)); err != nil {
return err
}
return nil
}
return jsonpretty.Format(w, bytes.NewReader(src), " ", f.colorize)
}

func (f *jsonFormatter) Match(t string) bool {
return jsonTypeRE.MatchString(t)
}
16 changes: 14 additions & 2 deletions pkg/api/client.go
Expand Up @@ -34,10 +34,22 @@ type ClientOptions struct {
// Host is the default host that API requests will be sent to.
Host string

// Log specifies a writer to write API request logs to.
// Default is no logging.
// Log specifies a writer to write API request logs to. Default is to respect the GH_DEBUG environment
// variable, and no logging otherwise.
Log io.Writer

// LogIgnoreEnv disables respecting the GH_DEBUG environment variable. This can be useful in test mode
// or when the extension already offers its own controls for logging to the user.
LogIgnoreEnv bool

// LogColorize enables colorized logging to Log for display in a terminal.
// Default is no coloring.
LogColorize bool

// LogVerboseHTTP enables logging HTTP headers and bodies to Log.
// Default is only logging request URLs and response statuses.
LogVerboseHTTP bool

// SkipDefaultHeaders disables setting of the default headers.
SkipDefaultHeaders bool

Expand Down
144 changes: 144 additions & 0 deletions pkg/jsonpretty/format.go
@@ -0,0 +1,144 @@
// Package jsonpretty implements a terminal pretty-printer for JSON.
package jsonpretty

import (
"bytes"
"encoding/json"
"fmt"
"io"
"strings"
)

const (
colorDelim = "\x1b[1;38m" // bright white
colorKey = "\x1b[1;34m" // bright blue
colorNull = "\x1b[36m" // cyan
colorString = "\x1b[32m" // green
colorBool = "\x1b[33m" // yellow
colorReset = "\x1b[m"
)

// Format reads JSON from r and writes a prettified version of it to w.
func Format(w io.Writer, r io.Reader, indent string, colorize bool) error {
dec := json.NewDecoder(r)
dec.UseNumber()

c := func(ansi string) string {
if !colorize {
return ""
}
return ansi
}

var idx int
var stack []json.Delim

for {
t, err := dec.Token()
if err == io.EOF {
break
}
if err != nil {
return err
}

switch tt := t.(type) {
case json.Delim:
switch tt {
case '{', '[':
stack = append(stack, tt)
idx = 0
if _, err := fmt.Fprint(w, c(colorDelim), tt, c(colorReset)); err != nil {
return err
}
if dec.More() {
if _, err := fmt.Fprint(w, "\n", strings.Repeat(indent, len(stack))); err != nil {
return err
}
}
continue
case '}', ']':
stack = stack[:len(stack)-1]
idx = 0
if _, err := fmt.Fprint(w, c(colorDelim), tt, c(colorReset)); err != nil {
return err
}
}
default:
b, err := marshalJSON(tt)
if err != nil {
return err
}

isKey := len(stack) > 0 && stack[len(stack)-1] == '{' && idx%2 == 0
idx++

var color string
if isKey {
color = colorKey
} else if tt == nil {
color = colorNull
} else {
switch t.(type) {
case string:
color = colorString
case bool:
color = colorBool
}
}

if color != "" {
if _, err := fmt.Fprint(w, c(color)); err != nil {
return err
}
}
if _, err := w.Write(b); err != nil {
return err
}
if color != "" {
if _, err := fmt.Fprint(w, c(colorReset)); err != nil {
return err
}
}

if isKey {
if _, err := fmt.Fprint(w, c(colorDelim), ":", c(colorReset), " "); err != nil {
return err
}
continue
}
}

if dec.More() {
if _, err := fmt.Fprint(w, c(colorDelim), ",", c(colorReset), "\n", strings.Repeat(indent, len(stack))); err != nil {
return err
}
} else if len(stack) > 0 {
if _, err := fmt.Fprint(w, "\n", strings.Repeat(indent, len(stack)-1)); err != nil {
return err
}
} else {
if _, err := fmt.Fprint(w, "\n"); err != nil {
return err
}
}
}

return nil
}

// marshalJSON works like json.Marshal, but with HTML-escaping disabled.
func marshalJSON(v interface{}) ([]byte, error) {
buf := bytes.Buffer{}
enc := json.NewEncoder(&buf)
enc.SetEscapeHTML(false)
if err := enc.Encode(v); err != nil {
return nil, err
}
bb := buf.Bytes()
// omit trailing newline added by json.Encoder
if len(bb) > 0 && bb[len(bb)-1] == '\n' {
return bb[:len(bb)-1], nil
}
return bb, nil
}

0 comments on commit d7a6f56

Please sign in to comment.