Repository: go-logr/logr
Pull request #147 (2022-08-02 00:17:47)

If logging as JSON and the type is json.RawMessage log it "as-is"
If we're already producing JSON and a sub message field is json.RawMessage (i.e. []byte) then emit it as-is.

Otherwise you get [X,Y,Z,..] style which is pretty useless in the log in that form.

pohly: I'm not sure about this. How would code know that it is okay to pass a `json.RawMessage` as a value? This is only useful in code which will only ever be used with funcr configured to emit JSON output, which kind of defeats the purpose of go-logr as a general-purpose logging API.

sfc-gh-jchacon: That's why this is in the funcr specific code that is logging in JSON format. It's scoped directly to that and not in the general case on purpose. 

The reason for it is if you have a json.RawMessage you likely want to see it in string form not [X,Y,Z] form. Converting it to string by casting to string also doesn't work as the pretty printer gets involved at that point and escapes all the JSON.
sfc-gh-jchacon: The other option would be to add a struct tag which adds an option when logging which says "just stringify this as-is".

i.e.

type Message struct {
  Data json.RawMessage `json:"data` `funcr:"stringify"`
}

So instead of [X,Y,Z] you'd just get the json string in there directly.

Thoughts?

pohly: > That's why this is in the funcr specific code that is logging in JSON format. It's scoped directly to that and not in the general case on purpose.

Let me rephrase: how will this feature be used in log calls? How does that code know that passing such a special value is okay? Or is this code never meant to be used with any logger other than funcr with JSON output?

sfc-gh-jchacon: > > That's why this is in the funcr specific code that is logging in JSON format. It's scoped directly to that and not in the general case on purpose.
> 
> Let me rephrase: how will this feature be used in log calls? How does that code know that passing such a special value is okay? Or is this code never meant to be used with any logger other than funcr with JSON output?

Yes, that's the idea. This is specific to funcr and its ability to easily render as JSON instead of KV pairs. 

My working example of this was a gRPC server that was taking a proto.Message and serializing as JSON before passing to OPA for policy evaluation. The OPA system sees the []byte and can treat that as a direct string but we can't log the request in human readable format today without this. i.e. [X,Y,Z] form or I cast the RawMessage to a string but then the pretty printer turns it into escaped JSON which isn't useful either.
thockin: Any desire to finish this one?

Patch:
diff --git a/funcr/funcr.go b/funcr/funcr.go
index 7accdb0..99dfe42 100644
--- a/funcr/funcr.go
+++ b/funcr/funcr.go
@@ -37,6 +37,7 @@ package funcr
 import (
 	"bytes"
 	"encoding"
+	"encoding/json"
 	"fmt"
 	"path/filepath"
 	"reflect"
@@ -500,6 +501,20 @@ func (f Formatter) prettyWithFlags(value interface{}, flags uint32, depth int) s
 		}
 		return buf.String()
 	case reflect.Slice, reflect.Array:
+		// If this is outputing as JSON make sure this isn't really a json.RawMessage.
+		// If so just emit "as-is" and don't pretty it as that will just print
+		// it as [X,Y,Z,...] which isn't terribly useful vs the string form you really want.
+		if f.outputFormat == outputJSON {
+			if rm, ok := value.(json.RawMessage); ok {
+				// If it's empty make sure we emit an empty value as the array style would below.
+				if len(rm) > 0 {
+					buf.Write(rm)
+				} else {
+					buf.WriteString("null")
+				}
+				return buf.String()
+			}
+		}
 		buf.WriteByte('[')
 		for i := 0; i < v.Len(); i++ {
 			if i > 0 {


Test patch:
diff --git a/funcr/funcr_test.go b/funcr/funcr_test.go
index b888fe4..20b26a5 100644
--- a/funcr/funcr_test.go
+++ b/funcr/funcr_test.go
@@ -230,6 +230,10 @@ type Tembedjsontags struct {
 	Tinner6 `json:"inner6,omitempty"`
 }
 
+type Trawjson struct {
+	Message json.RawMessage `json:"message"`
+}
+
 func TestPretty(t *testing.T) {
 	// used below
 	newStr := func(s string) *string {
@@ -669,6 +673,15 @@ func makeKV(args ...interface{}) []interface{} {
 }
 
 func TestRender(t *testing.T) {
+	// used below
+	raw := &Trawjson{}
+	marshal := &TjsontagsInt{}
+	var err error
+	raw.Message, err = json.Marshal(marshal)
+	if err != nil {
+		t.Fatalf("json.Marshal error: %v", err)
+	}
+
 	testCases := []struct {
 		name       string
 		builtins   []interface{}
@@ -738,6 +751,21 @@ func TestRender(t *testing.T) {
 		}{"arg", 789}, "val"),
 		expectKV:   `"<non-string-key: {"F1":"builtin",>"="val" "<non-string-key: {\"F1\":\"value\",\"F>"="val" "<non-string-key: {\"F1\":\"arg\",\"F2\">"="val"`,
 		expectJSON: `{"<non-string-key: {"F1":"builtin",>":"val","<non-string-key: {\"F1\":\"value\",\"F>":"val","<non-string-key: {\"F1\":\"arg\",\"F2\">":"val"}`,
+	}, {
+		name:       "json rendering with json.RawMessage",
+		args:       makeKV("key", raw),
+		expectKV:   `"key"={"message":[123,34,105,110,116,49,34,58,48,44,34,45,34,58,48,44,34,73,110,116,53,34,58,48,125]}`,
+		expectJSON: `{"key":{"message":{"int1":0,"-":0,"Int5":0}}}`,
+	}, {
+		name:       "byte array not json.RawMessage",
+		args:       makeKV("key", []byte{1, 2, 3, 4}),
+		expectKV:   `"key"=[1,2,3,4]`,
+		expectJSON: `{"key":[1,2,3,4]}`,
+	}, {
+		name:       "json rendering with empty json.RawMessage",
+		args:       makeKV("key", &Trawjson{}),
+		expectKV:   `"key"={"message":[]}`,
+		expectJSON: `{"key":{"message":null}}`,
 	}}
 
 	for _, tc := range testCases {