Skip to content

Fix raw byte array formatting in logs for json.RawMessage fields #3674

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Open
wants to merge 5 commits into
base: master
Choose a base branch
from
Open
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
26 changes: 18 additions & 8 deletions cns/logger/cnslogger.go
Original file line number Diff line number Diff line change
Expand Up @@ -136,12 +136,15 @@ func (c *CNSLogger) Request(tag string, request any, err error) {
if c.th == nil || c.disableTraceLogging {
return
}

requestString := log.ToJSONString(request)

var msg string
lvl := ai.InfoLevel
if err == nil {
msg = fmt.Sprintf("[%s] Received %T %+v.", tag, request, request)
msg = fmt.Sprintf("[%s] Received %T %s.", tag, request, requestString)
} else {
msg = fmt.Sprintf("[%s] Failed to decode %T %+v %s.", tag, request, request, err.Error())
msg = fmt.Sprintf("[%s] Failed to decode %T %s %s.", tag, request, requestString, err.Error())
lvl = ai.ErrorLevel
}
c.sendTraceInternal(msg, lvl)
Expand All @@ -152,16 +155,19 @@ func (c *CNSLogger) Response(tag string, response any, returnCode types.Response
if c.th == nil || c.disableTraceLogging {
return
}

responseString := log.ToJSONString(response)

var msg string
lvl := ai.InfoLevel
switch {
case err == nil && returnCode == 0:
msg = fmt.Sprintf("[%s] Sent %T %+v.", tag, response, response)
msg = fmt.Sprintf("[%s] Sent %T %s.", tag, response, responseString)
case err != nil:
msg = fmt.Sprintf("[%s] Code:%s, %+v %s.", tag, returnCode.String(), response, err.Error())
msg = fmt.Sprintf("[%s] Code:%s, %s %s.", tag, returnCode.String(), responseString, err.Error())
lvl = ai.ErrorLevel
default:
msg = fmt.Sprintf("[%s] Code:%s, %+v.", tag, returnCode.String(), response)
msg = fmt.Sprintf("[%s] Code:%s, %s.", tag, returnCode.String(), responseString)
}
c.sendTraceInternal(msg, lvl)
}
Expand All @@ -171,16 +177,20 @@ func (c *CNSLogger) ResponseEx(tag string, request, response any, returnCode typ
if c.th == nil || c.disableTraceLogging {
return
}

requestString := log.ToJSONString(request)
responseString := log.ToJSONString(response)

var msg string
lvl := ai.InfoLevel
switch {
case err == nil && returnCode == 0:
msg = fmt.Sprintf("[%s] Sent %T %+v %T %+v.", tag, request, request, response, response)
msg = fmt.Sprintf("[%s] Sent %T %s %T %s.", tag, request, requestString, response, responseString)
case err != nil:
msg = fmt.Sprintf("[%s] Code:%s, %+v, %+v, %s.", tag, returnCode.String(), request, response, err.Error())
msg = fmt.Sprintf("[%s] Code:%s, %s, %s, %s.", tag, returnCode.String(), requestString, responseString, err.Error())
lvl = ai.ErrorLevel
default:
msg = fmt.Sprintf("[%s] Code:%s, %+v, %+v.", tag, returnCode.String(), request, response)
msg = fmt.Sprintf("[%s] Code:%s, %s, %s.", tag, returnCode.String(), requestString, responseString)
}
c.sendTraceInternal(msg, lvl)
}
Expand Down
33 changes: 25 additions & 8 deletions log/logger.go
Original file line number Diff line number Diff line change
Expand Up @@ -4,6 +4,7 @@
package log

import (
"encoding/json"
"fmt"
"io"
"log"
Expand Down Expand Up @@ -199,34 +200,50 @@ func (logger *Logger) rotate() error {
return nil
}

// ToJSONString converts any object to a JSON string for logging purposes.
// When the object contains json.RawMessage fields, they will be properly formatted
// instead of being shown as byte arrays. Falls back to %+v if JSON marshaling fails.
func ToJSONString(obj interface{}) string {
if obj == nil {
return "null"
}

bytes, err := json.Marshal(obj)
if err != nil {
// Fall back to standard formatting if JSON marshaling fails
return fmt.Sprintf("%+v", obj)
}
return string(bytes)
}

// Request logs a structured request.
func (logger *Logger) Request(tag string, request interface{}, err error) {
if err == nil {
logger.Printf("[%s] Received %T %+v.", tag, request, request)
logger.Printf("[%s] Received %T %s.", tag, request, ToJSONString(request))
} else {
logger.Errorf("[%s] Failed to decode %T %+v %s.", tag, request, request, err.Error())
logger.Errorf("[%s] Failed to decode %T %s %s.", tag, request, ToJSONString(request), err.Error())
}
}

// Response logs a structured response.
func (logger *Logger) Response(tag string, response interface{}, returnCode int, returnStr string, err error) {
if err == nil && returnCode == 0 {
logger.Printf("[%s] Sent %T %+v.", tag, response, response)
logger.Printf("[%s] Sent %T %s.", tag, response, ToJSONString(response))
} else if err != nil {
logger.Errorf("[%s] Code:%s, %+v %s.", tag, returnStr, response, err.Error())
logger.Errorf("[%s] Code:%s, %s %s.", tag, returnStr, ToJSONString(response), err.Error())
} else {
logger.Errorf("[%s] Code:%s, %+v.", tag, returnStr, response)
logger.Errorf("[%s] Code:%s, %s.", tag, returnStr, ToJSONString(response))
}
}

// ResponseEx logs a structured response and the request associate with it.
func (logger *Logger) ResponseEx(tag string, request interface{}, response interface{}, returnCode int, returnStr string, err error) {
if err == nil && returnCode == 0 {
logger.Printf("[%s] Sent %T %+v %T %+v.", tag, request, request, response, response)
logger.Printf("[%s] Sent %T %s %T %s.", tag, request, ToJSONString(request), response, ToJSONString(response))
} else if err != nil {
logger.Errorf("[%s] Code:%s, %+v, %+v %s.", tag, returnStr, request, response, err.Error())
logger.Errorf("[%s] Code:%s, %s, %s %s.", tag, returnStr, ToJSONString(request), ToJSONString(response), err.Error())
} else {
logger.Errorf("[%s] Code:%s, %+v, %+v.", tag, returnStr, request, response)
logger.Errorf("[%s] Code:%s, %s, %s.", tag, returnStr, ToJSONString(request), ToJSONString(response))
}
}

Expand Down
65 changes: 65 additions & 0 deletions log/logger_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -4,6 +4,7 @@
package log

import (
"encoding/json"
"fmt"
"os"
"path"
Expand All @@ -18,6 +19,70 @@ const (
logName = "test"
)

func TestToJSONString(t *testing.T) {
tests := []struct {
name string
input interface{}
expected string
}{
{
name: "nil value",
input: nil,
expected: "null",
},
{
name: "simple struct",
input: struct{ Name string }{"test"},
expected: `{"Name":"test"}`,
},
{
name: "struct with json.RawMessage",
input: struct {
ID string
Data json.RawMessage
Enabled bool
}{
ID: "123",
Data: json.RawMessage(`{"foo":"bar"}`),
Enabled: true,
},
expected: `{"ID":"123","Data":{"foo":"bar"},"Enabled":true}`,
},
{
name: "nested json.RawMessage",
input: struct {
Context json.RawMessage
}{
Context: json.RawMessage(`{"PodName":"test-pod","PodNamespace":"default"}`),
},
expected: `{"Context":{"PodName":"test-pod","PodNamespace":"default"}}`,
},
}

for _, test := range tests {
t.Run(test.name, func(t *testing.T) {
result := ToJSONString(test.input)
assert.Equal(t, test.expected, result)
})
}
}

func TestToJSONStringFallback(t *testing.T) {
// Create a circular reference that cannot be marshaled to JSON
type Circular struct {
Name string
Referrer *Circular
}

circular := &Circular{Name: "test"}
circular.Referrer = circular // Create circular reference

// This should fall back to %+v formatting
result := ToJSONString(circular)
assert.Contains(t, result, "test")
assert.Contains(t, result, "Referrer")
}

func TestNewLoggerError(t *testing.T) {
// we expect an error from NewLoggerE in the event that we provide an
// unwriteable directory
Expand Down
Loading