Fix HTTP proxy logging (#169)

johnstairs · web-flow · commit a76356fe4ed9 · 2025-01-27T17:40:16.000Z
diff --git a/cli/integrationtest/httpproxy_test.go b/cli/integrationtest/httpproxy_test.go
@@ -11,6 +11,7 @@ import (
 	"path"
 	"testing"
 
+	"github.com/microsoft/tyger/cli/internal/install"
 	"github.com/stretchr/testify/require"
 )
 
@@ -83,19 +84,37 @@ logPath: /logs
 
 	s.CommandSucceeds("start", "tyger-proxy")
 
-	squidProxy := "squid:3128"
+	squidProxy := "http://squid:3128"
 
 	// Test tyger using the Squid proxy
-	_, _, err = s.ShellExec("tyger-proxy", fmt.Sprintf("curl --fail %s/v1/metadata", tygerUri))
+	stdOut, stdErr, err := s.ShellExec("tyger-proxy", fmt.Sprintf("curl --fail %s/v1/metadata -v", tygerUri))
+	t.Log("stdout", stdOut)
+	t.Log("stdErr", stdErr)
 	require.Error(t, err, "curl should fail because the proxy is not used")
 	s.ShellExecSucceeds("tyger-proxy", fmt.Sprintf("curl --retry 5 --proxy %s --fail %s/v1/metadata", squidProxy, tygerUri))
 
 	// Specify the proxy via environment variable
-	s.ShellExecSucceeds("tyger-proxy", fmt.Sprintf("export HTTPS_PROXY=%s && tyger login -f /creds.yml && tyger buffer read %s > /dev/null", squidProxy, bufferId))
+	s.ShellExecSucceeds("tyger-proxy", fmt.Sprintf("export HTTPS_PROXY=%s && tyger login -f /creds.yml --log-level trace && tyger buffer read %s > /dev/null", squidProxy, bufferId))
 
 	// Specify the proxy in the config file
 	s.ShellExecSucceeds("tyger-proxy", fmt.Sprintf("echo 'proxy: %s' >> /creds.yml", squidProxy))
-	s.ShellExecSucceeds("tyger-proxy", fmt.Sprintf("tyger login -f /creds.yml && tyger buffer read %s > /dev/null", bufferId))
+
+	_, stdErr, err = s.ShellExec("tyger-proxy", "tyger login -f /creds.yml --log-level trace --log-format json")
+	require.NoError(t, err, "tyger login should succeed", stdErr)
+
+	parsedLogLines, err := install.ParseJsonLogs([]byte(stdErr))
+	require.NoError(t, err, "failed to parse log lines")
+	foundCount := 0
+	for _, line := range parsedLogLines {
+		if line["message"] == "Sending request" {
+			foundCount++
+			proxyLogEntry := line["proxy"]
+			require.Equal(t, squidProxy, proxyLogEntry, "proxy argument missing from log entry")
+		}
+	}
+	require.Greater(t, foundCount, 0, "no log entries found with proxy argument")
+
+	s.ShellExecSucceeds("tyger-proxy", fmt.Sprintf("tyger buffer read %s > /dev/null", bufferId))
 
 	// Now start up the tyger proxy
 	s.ShellExecSucceeds("tyger-proxy", "tyger-proxy start -f /creds.yml")
diff --git a/cli/internal/client/client.go b/cli/internal/client/client.go
@@ -27,9 +27,8 @@ const (
 )
 
 var (
-	underlyingHttpTransport = http.DefaultTransport.(*http.Transport)
-	DefaultClient           *Client
-	DefaultRetryableClient  *retryablehttp.Client
+	DefaultClient          *Client
+	DefaultRetryableClient *retryablehttp.Client
 )
 
 func GetDefaultSocketUrl() string {
@@ -47,10 +46,6 @@ type MakeDialer func(next dialContextFunc) dialContextFunc
 
 type dialContextFunc func(ctx context.Context, network, address string) (net.Conn, error)
 
-type roundTripFunc func(req *http.Request) (*http.Response, error)
-
-func (f roundTripFunc) RoundTrip(req *http.Request) (*http.Response, error) { return f(req) }
-
 type Client struct {
 	*retryablehttp.Client
 	transport               http.RoundTripper
@@ -93,7 +88,7 @@ func NewClient(opts *ClientOptions) (*Client, error) {
 	var roundTripper http.RoundTripper = transport
 
 	if opts.CreateTransport == nil {
-		opts.CreateTransport = makeUnixTransport
+		opts.CreateTransport = makeUnixAwareTransport
 	}
 
 	roundTripper = opts.CreateTransport(roundTripper)
@@ -196,11 +191,28 @@ func (c *TygerClient) ConnectionType() TygerConnectionType {
 
 type HttpTransportOption func(*http.Transport)
 
+func getHttpTransport(roudtripper http.RoundTripper) *http.Transport {
+	if transport, ok := roudtripper.(*http.Transport); ok {
+		return transport
+	}
+
+	if exposer, ok := roudtripper.(HttpTransportExposer); ok {
+		return exposer.GetUnderlyingTransport()
+	}
+
+	panic(fmt.Sprintf("could not get *http.Transport from %T", roudtripper))
+}
+
+type HttpTransportExposer interface {
+	GetUnderlyingTransport() *http.Transport
+}
+
 type loggingTransport struct {
 	http.RoundTripper
 }
 
 func (t *loggingTransport) RoundTrip(req *http.Request) (*http.Response, error) {
+	underlyingHttpTransport := getHttpTransport(t.RoundTripper)
 	proxy, err := underlyingHttpTransport.Proxy(req)
 	if err != nil {
 		return nil, fmt.Errorf("error getting proxy: %w", err)
@@ -232,6 +244,12 @@ func (t *loggingTransport) RoundTrip(req *http.Request) (*http.Response, error)
 	return resp, err
 }
 
+func (t *loggingTransport) GetUnderlyingTransport() *http.Transport {
+	return getHttpTransport(t.RoundTripper)
+}
+
+var _ HttpTransportExposer = &loggingTransport{}
+
 func ParseProxy(proxyString string) (func(r *http.Request) (*url.URL, error), error) {
 	switch proxyString {
 	case "none":
diff --git a/cli/internal/client/commandtransport.go b/cli/internal/client/commandtransport.go
@@ -94,6 +94,12 @@ func (c *CommandTransport) RoundTrip(req *http.Request) (*http.Response, error)
 	return resp, nil
 }
 
+func (c *CommandTransport) GetUnderlyingTransport() *http.Transport {
+	return getHttpTransport(c.next)
+}
+
+var _ HttpTransportExposer = &CommandTransport{}
+
 type cleanupOnCloseReader struct {
 	io.ReadCloser
 	cleanup func()
diff --git a/cli/internal/client/unixtransport.go b/cli/internal/client/unixtransport.go
@@ -35,47 +35,59 @@ func makeUnixDialer(next dialContextFunc) dialContextFunc {
 	}
 }
 
-func makeUnixTransport(next http.RoundTripper) http.RoundTripper {
-	return roundTripFunc(func(req *http.Request) (*http.Response, error) {
-		if req.URL == nil {
-			return next.RoundTrip(req)
-		}
+type unixAwareTransport struct {
+	next http.RoundTripper
+}
 
-		var scheme string
-		switch req.URL.Scheme {
-		case "http+unix":
-			scheme = "http"
-		case "https+unix":
-			scheme = "https"
-		default:
-			return next.RoundTrip(req)
-		}
+func makeUnixAwareTransport(next http.RoundTripper) http.RoundTripper {
+	return &unixAwareTransport{next: next}
+}
 
-		parts := strings.SplitN(req.URL.Path, ":", 2)
-		var socketPath string
-		var requestPath string
-
-		switch len(parts) {
-		case 1:
-			socketPath = parts[0]
-			requestPath = ""
-		case 2:
-			socketPath = parts[0]
-			requestPath = parts[1]
-		default:
-			return nil, errors.New("unix transport: invalid path")
-		}
+func (t *unixAwareTransport) RoundTrip(req *http.Request) (*http.Response, error) {
+	if req.URL == nil {
+		return t.next.RoundTrip(req)
+	}
 
-		req = req.Clone(req.Context())
+	var scheme string
+	switch req.URL.Scheme {
+	case "http+unix":
+		scheme = "http"
+	case "https+unix":
+		scheme = "https"
+	default:
+		return t.next.RoundTrip(req)
+	}
 
-		req.URL.Scheme = scheme
-		req.URL.Host = encodeUnixPathToHost(socketPath)
-		req.URL.Path = requestPath
+	parts := strings.SplitN(req.URL.Path, ":", 2)
+	var socketPath string
+	var requestPath string
+
+	switch len(parts) {
+	case 1:
+		socketPath = parts[0]
+		requestPath = ""
+	case 2:
+		socketPath = parts[0]
+		requestPath = parts[1]
+	default:
+		return nil, errors.New("unix transport: invalid path")
+	}
+
+	req = req.Clone(req.Context())
+
+	req.URL.Scheme = scheme
+	req.URL.Host = encodeUnixPathToHost(socketPath)
+	req.URL.Path = requestPath
 
-		return next.RoundTrip(req)
-	})
+	return t.next.RoundTrip(req)
 }
 
+func (t *unixAwareTransport) GetUnderlyingTransport() *http.Transport {
+	return getHttpTransport(t.next)
+}
+
+var _ HttpTransportExposer = &unixAwareTransport{}
+
 func encodeUnixPathToHost(socketPath string) string {
 	return fmt.Sprintf("!unix!%s", encoding.EncodeToString([]byte(socketPath)))
 }
