Merge pull request #194 from hyperledger/better-http-trace

Fix trace level logging

Author: EnriqueL8

pkg/ffresty/ffresty.go

@@ -20,6 +20,7 @@ import (
 	"context"
 	"crypto/tls"
 	"encoding/base64"
+	"encoding/json"
 	"fmt"
 	"io"
 	"net"
@@ -315,7 +316,9 @@ func NewWithConfig(ctx context.Context, ffrestyConfig Config) (client *resty.Cli
 		}
 
 		log.L(rCtx).Debugf("==> %s %s%s", req.Method, _url, req.URL)
-		log.L(rCtx).Tracef("==> (body) %+v", req.Body)
+		if logrus.IsLevelEnabled(logrus.TraceLevel) {
+			log.L(rCtx).Tracef("==> (body) %s", traceBody(req.Body))
+		}
 
 		return nil
 	})
@@ -373,6 +376,24 @@ func NewWithConfig(ctx context.Context, ffrestyConfig Config) (client *resty.Cli
 	return client
 }
 
+func traceBody(v any) string {
+	switch vt := v.(type) {
+	case string:
+		return vt
+	case []byte:
+		return string(vt)
+	case nil:
+		return ""
+	default:
+		_, isReader := v.(io.Reader)
+		if isReader {
+			return "(binary reader)" // Future work could create a pipe to log the chunks if that were required
+		}
+		jv, _ := json.Marshal(v)
+		return string(jv)
+	}
+}
+
 func WrapRestErr(ctx context.Context, res *resty.Response, err error, key i18n.ErrorMessageKey) error {
 	var respData string
 	if res != nil {

pkg/ffresty/ffresty_test.go

@@ -45,10 +45,12 @@ import (
 	"github.com/hyperledger/firefly-common/pkg/fftls"
 	"github.com/hyperledger/firefly-common/pkg/i18n"
 	"github.com/hyperledger/firefly-common/pkg/metric"
+	"github.com/sirupsen/logrus"
 	"golang.org/x/time/rate"
 
 	"github.com/jarcoal/httpmock"
 	"github.com/stretchr/testify/assert"
+	"github.com/stretchr/testify/require"
 )
 
 const configDir = "../../test/data/config"
@@ -608,6 +610,8 @@ func TestBadKeyPair(t *testing.T) {
 }
 
 func TestMTLSClientWithServer(t *testing.T) {
+	logrus.SetLevel(logrus.TraceLevel)
+
 	// Create an X509 certificate pair
 	privatekey, _ := rsa.GenerateKey(rand.Reader, 2048)
 	publickey := &privatekey.PublicKey
@@ -661,13 +665,11 @@ func TestMTLSClientWithServer(t *testing.T) {
 
 	ctx, cancelCtx := context.WithCancel(context.Background())
 	go func() {
-		select {
-		case <-ctx.Done():
-			shutdownContext, cancel := context.WithTimeout(context.Background(), 2*time.Second)
-			defer cancel()
-			if err := server.Shutdown(shutdownContext); err != nil {
-				return
-			}
+		<-ctx.Done()
+		shutdownContext, cancel := context.WithTimeout(context.Background(), 2*time.Second)
+		defer cancel()
+		if err := server.Shutdown(shutdownContext); err != nil {
+			return
 		}
 	}()
 
@@ -809,3 +811,11 @@ func TestHooks(t *testing.T) {
 	assert.Equal(t, onSuccessCount, 1)
 
 }
+
+func TestTrace(t *testing.T) {
+	require.Equal(t, "plain", traceBody("plain"))
+	require.Equal(t, "plain", traceBody([]byte("plain")))
+	require.Equal(t, "", traceBody(nil))
+	require.JSONEq(t, `{"some":"data"}`, traceBody(map[string]string{"some": "data"}))
+	require.Equal(t, `(binary reader)`, traceBody(strings.NewReader("data to stream")))
+}