Skip to content
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

feat: enable request logging via the --debug flag #226

Merged
merged 14 commits into from
Dec 2, 2022
Merged
2 changes: 1 addition & 1 deletion cmd/start.go
Original file line number Diff line number Diff line change
Expand Up @@ -84,7 +84,7 @@ var startCmd = &cobra.Command{
if err != nil {
log.Fatalf("can't initialize zap logger: %v", err)
}
logger := logger.NewLogger(l)
logger := logger.NewLogger(l, !Debug)
rtLogger := logger.WithFields(zap.String("component", "start"))

// Build Runtime -----------------------------------------------------------
Expand Down
2 changes: 1 addition & 1 deletion pkg/eval/fractional_evaluation_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -281,7 +281,7 @@ func TestFractionalEvaluation(t *testing.T) {
const reqID = "default"
for name, tt := range tests {
t.Run(name, func(t *testing.T) {
je := NewJSONEvaluator(logger.NewLogger(nil))
je := NewJSONEvaluator(logger.NewLogger(nil, true))
je.state = tt.flags

value, variant, reason, err := resolve[string](
Expand Down
16 changes: 8 additions & 8 deletions pkg/eval/json_evaluator_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -275,7 +275,7 @@ var Flags = fmt.Sprintf(`{
DisabledFlag)

func TestGetState_Valid_ContainsFlag(t *testing.T) {
evaluator := eval.JSONEvaluator{Logger: logger.NewLogger(nil)}
evaluator := eval.JSONEvaluator{Logger: logger.NewLogger(nil, true)}
_, err := evaluator.SetState("", ValidFlags)
if err != nil {
t.Fatalf("Expected no error")
Expand All @@ -295,7 +295,7 @@ func TestGetState_Valid_ContainsFlag(t *testing.T) {
}

func TestSetState_Invalid_Error(t *testing.T) {
evaluator := eval.JSONEvaluator{Logger: logger.NewLogger(nil)}
evaluator := eval.JSONEvaluator{Logger: logger.NewLogger(nil, true)}

// set state with an invalid flag definition
_, err := evaluator.SetState("", InvalidFlags)
Expand All @@ -305,7 +305,7 @@ func TestSetState_Invalid_Error(t *testing.T) {
}

func TestSetState_Valid_NoError(t *testing.T) {
evaluator := eval.JSONEvaluator{Logger: logger.NewLogger(nil)}
evaluator := eval.JSONEvaluator{Logger: logger.NewLogger(nil, true)}

// set state with a valid flag definition
_, err := evaluator.SetState("", ValidFlags)
Expand All @@ -329,7 +329,7 @@ func TestResolveBooleanValue(t *testing.T) {
{DisabledFlag, nil, StaticBoolValue, model.ErrorReason, model.FlagDisabledErrorCode},
}
const reqID = "default"
evaluator := eval.JSONEvaluator{Logger: logger.NewLogger(nil)}
evaluator := eval.JSONEvaluator{Logger: logger.NewLogger(nil, true)}
_, err := evaluator.SetState("", Flags)
if err != nil {
t.Fatalf("Expected no error")
Expand Down Expand Up @@ -368,7 +368,7 @@ func TestResolveStringValue(t *testing.T) {
{DisabledFlag, nil, "", model.ErrorReason, model.FlagDisabledErrorCode},
}
const reqID = "default"
evaluator := eval.JSONEvaluator{Logger: logger.NewLogger(nil)}
evaluator := eval.JSONEvaluator{Logger: logger.NewLogger(nil, true)}
_, err := evaluator.SetState("", Flags)
if err != nil {
t.Fatalf("Expected no error")
Expand Down Expand Up @@ -408,7 +408,7 @@ func TestResolveFloatValue(t *testing.T) {
{DisabledFlag, nil, 0, model.ErrorReason, model.FlagDisabledErrorCode},
}
const reqID = "default"
evaluator := eval.JSONEvaluator{Logger: logger.NewLogger(nil)}
evaluator := eval.JSONEvaluator{Logger: logger.NewLogger(nil, true)}
_, err := evaluator.SetState("", Flags)
if err != nil {
t.Fatalf("Expected no error")
Expand Down Expand Up @@ -448,7 +448,7 @@ func TestResolveIntValue(t *testing.T) {
{DisabledFlag, nil, 0, model.ErrorReason, model.FlagDisabledErrorCode},
}
const reqID = "default"
evaluator := eval.JSONEvaluator{Logger: logger.NewLogger(nil)}
evaluator := eval.JSONEvaluator{Logger: logger.NewLogger(nil, true)}
_, err := evaluator.SetState("", Flags)
if err != nil {
t.Fatalf("Expected no error")
Expand Down Expand Up @@ -488,7 +488,7 @@ func TestResolveObjectValue(t *testing.T) {
{DisabledFlag, nil, "{}", model.ErrorReason, model.FlagDisabledErrorCode},
}
const reqID = "default"
evaluator := eval.JSONEvaluator{Logger: logger.NewLogger(nil)}
evaluator := eval.JSONEvaluator{Logger: logger.NewLogger(nil, true)}
_, err := evaluator.SetState("", Flags)
if err != nil {
t.Fatalf("Expected no error")
Expand Down
47 changes: 37 additions & 10 deletions pkg/logger/logger.go
Original file line number Diff line number Diff line change
Expand Up @@ -37,12 +37,16 @@ WrappedLogger.DebugWithID("myID", "my log line")
const RequestIDFieldName = "requestID"

type Logger struct {
requestFields *sync.Map
Logger *zap.Logger
fields []zap.Field
requestFields *sync.Map
Logger *zap.Logger
fields []zap.Field
noopReqIDLogging bool
}

func (l *Logger) DebugWithID(reqID string, msg string, fields ...zap.Field) {
if l.noopReqIDLogging {
return
}
if ce := l.Logger.Check(zap.DebugLevel, msg); ce != nil {
fields = append(fields, l.getFieldsForLog(reqID)...)
ce.Write(fields...)
Expand All @@ -57,6 +61,9 @@ func (l *Logger) Debug(msg string, fields ...zap.Field) {
}

func (l *Logger) InfoWithID(reqID string, msg string, fields ...zap.Field) {
if l.noopReqIDLogging {
return
}
if ce := l.Logger.Check(zap.InfoLevel, msg); ce != nil {
fields = append(fields, l.getFieldsForLog(reqID)...)
ce.Write(fields...)
Expand All @@ -71,6 +78,9 @@ func (l *Logger) Info(msg string, fields ...zap.Field) {
}

func (l *Logger) WarnWithID(reqID string, msg string, fields ...zap.Field) {
if l.noopReqIDLogging {
return
}
if ce := l.Logger.Check(zap.WarnLevel, msg); ce != nil {
fields = append(fields, l.getFieldsForLog(reqID)...)
ce.Write(fields...)
Expand All @@ -85,6 +95,9 @@ func (l *Logger) Warn(msg string, fields ...zap.Field) {
}

func (l *Logger) ErrorWithID(reqID string, msg string, fields ...zap.Field) {
if l.noopReqIDLogging {
return
}
if ce := l.Logger.Check(zap.ErrorLevel, msg); ce != nil {
fields = append(fields, l.getFieldsForLog(reqID)...)
ce.Write(fields...)
Expand All @@ -99,6 +112,9 @@ func (l *Logger) Error(msg string, fields ...zap.Field) {
}

func (l *Logger) FatalWithID(reqID string, msg string, fields ...zap.Field) {
if l.noopReqIDLogging {
return
}
if ce := l.Logger.Check(zap.FatalLevel, msg); ce != nil {
fields = append(fields, l.getFieldsForLog(reqID)...)
ce.Write(fields...)
Expand All @@ -115,6 +131,9 @@ func (l *Logger) Fatal(msg string, fields ...zap.Field) {
// WriteFields adds field key and value pairs to the highest level Logger, they will be applied to all
// subsequent log calls using the matching requestID
func (l *Logger) WriteFields(reqID string, fields ...zap.Field) {
if l.noopReqIDLogging {
return
}
res := append(l.getFields(reqID), fields...)
l.requestFields.Store(reqID, res)
}
Expand All @@ -140,6 +159,9 @@ func (l *Logger) getFieldsForLog(reqID string) []zap.Field {

// ClearFields clears all stored fields for a given requestID, important for maintaining performance
func (l *Logger) ClearFields(reqID string) {
if l.noopReqIDLogging {
return
}
l.requestFields.Delete(reqID)
}

Expand Down Expand Up @@ -170,14 +192,18 @@ func NewZapLogger(level zapcore.Level) (*zap.Logger, error) {
}

// NewLogger returns the logging wrapper for a given *zap.logger,
// will return a wrapped zap noop logger if none is provided
func NewLogger(logger *zap.Logger) *Logger {
// Noop logger will bypass the setting of fields, improving performance
// if no *zap.Logger is nil, a noop logger will be set,
// and the noopReqIDLogging argument will be overwriten to true
func NewLogger(logger *zap.Logger, noopReqIDLogging bool) *Logger {
if logger == nil {
noopReqIDLogging = true
logger = zap.New(nil)
}
return &Logger{
Logger: logger.WithOptions(zap.AddCallerSkip(1)),
requestFields: &sync.Map{},
Logger: logger.WithOptions(zap.AddCallerSkip(1)),
requestFields: &sync.Map{},
noopReqIDLogging: noopReqIDLogging,
}
}

Expand All @@ -186,8 +212,9 @@ func NewLogger(logger *zap.Logger) *Logger {
// read/write from the highest level logging wrappers field pool
func (l *Logger) WithFields(fields ...zap.Field) *Logger {
return &Logger{
Logger: l.Logger,
requestFields: l.requestFields,
fields: fields,
Logger: l.Logger,
requestFields: l.requestFields,
fields: fields,
noopReqIDLogging: l.noopReqIDLogging,
}
}
4 changes: 2 additions & 2 deletions pkg/logger/logger_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -20,7 +20,7 @@ func TestFieldStorageAndRetrieval(t *testing.T) {
},
}
for name, test := range tests {
l := NewLogger(nil)
l := NewLogger(&zap.Logger{}, false)
l.WriteFields(name, test.fields...)
returnedFields := l.getFields(name)
if !reflect.DeepEqual(returnedFields, test.fields) {
Expand All @@ -32,7 +32,7 @@ func TestFieldStorageAndRetrieval(t *testing.T) {
func TestLoggerChildOperation(t *testing.T) {
id := "test"
// create parent logger
p := NewLogger(nil)
p := NewLogger(&zap.Logger{}, false)
// add field 1
field1 := zap.Int("field", 1)
p.WriteFields(id, field1)
Expand Down
22 changes: 11 additions & 11 deletions pkg/service/connect_service_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -87,7 +87,7 @@ func TestConnectService_UnixConnection(t *testing.T) {
ConnectServiceConfiguration: &service.ConnectServiceConfiguration{
ServerSocketPath: tt.socketPath,
},
Logger: logger.NewLogger(nil),
Logger: logger.NewLogger(nil, true),
}
ctx := context.Background()
ctx, cancel := context.WithTimeout(ctx, 5*time.Second)
Expand Down Expand Up @@ -181,7 +181,7 @@ func TestConnectService_ResolveBoolean(t *testing.T) {
).AnyTimes()
s := service.ConnectService{
Eval: eval,
Logger: logger.NewLogger(nil),
Logger: logger.NewLogger(nil, true),
}
got, err := s.ResolveBoolean(tt.functionArgs.ctx, connect.NewRequest(tt.functionArgs.req))
if err != nil && !errors.Is(err, tt.wantErr) {
Expand Down Expand Up @@ -229,7 +229,7 @@ func BenchmarkConnectService_ResolveBoolean(b *testing.B) {
).AnyTimes()
s := service.ConnectService{
Eval: eval,
Logger: logger.NewLogger(nil),
Logger: logger.NewLogger(nil, true),
}
b.Run(name, func(b *testing.B) {
for i := 0; i < b.N; i++ {
Expand Down Expand Up @@ -315,7 +315,7 @@ func TestConnectService_ResolveString(t *testing.T) {
)
s := service.ConnectService{
Eval: eval,
Logger: logger.NewLogger(nil),
Logger: logger.NewLogger(nil, true),
}
got, err := s.ResolveString(tt.functionArgs.ctx, connect.NewRequest(tt.functionArgs.req))
if (err != nil) && !errors.Is(err, tt.wantErr) {
Expand Down Expand Up @@ -364,7 +364,7 @@ func BenchmarkConnectService_ResolveString(b *testing.B) {

s := service.ConnectService{
Eval: eval,
Logger: logger.NewLogger(nil),
Logger: logger.NewLogger(nil, true),
}
b.Run(name, func(b *testing.B) {
for i := 0; i < b.N; i++ {
Expand Down Expand Up @@ -450,7 +450,7 @@ func TestConnectService_ResolveFloat(t *testing.T) {
).AnyTimes()
s := service.ConnectService{
Eval: eval,
Logger: logger.NewLogger(nil),
Logger: logger.NewLogger(nil, true),
}
got, err := s.ResolveFloat(tt.functionArgs.ctx, connect.NewRequest(tt.functionArgs.req))
if (err != nil) && !errors.Is(err, tt.wantErr) {
Expand Down Expand Up @@ -499,7 +499,7 @@ func BenchmarkConnectService_ResolveFloat(b *testing.B) {

s := service.ConnectService{
Eval: eval,
Logger: logger.NewLogger(nil),
Logger: logger.NewLogger(nil, true),
}
b.Run(name, func(b *testing.B) {
for i := 0; i < b.N; i++ {
Expand Down Expand Up @@ -585,7 +585,7 @@ func TestConnectService_ResolveInt(t *testing.T) {
).AnyTimes()
s := service.ConnectService{
Eval: eval,
Logger: logger.NewLogger(nil),
Logger: logger.NewLogger(nil, true),
}
got, err := s.ResolveInt(tt.functionArgs.ctx, connect.NewRequest(tt.functionArgs.req))
if (err != nil) && !errors.Is(err, tt.wantErr) {
Expand Down Expand Up @@ -634,7 +634,7 @@ func BenchmarkConnectService_ResolveInt(b *testing.B) {

s := service.ConnectService{
Eval: eval,
Logger: logger.NewLogger(nil),
Logger: logger.NewLogger(nil, true),
}
b.Run(name, func(b *testing.B) {
for i := 0; i < b.N; i++ {
Expand Down Expand Up @@ -724,7 +724,7 @@ func TestConnectService_ResolveObject(t *testing.T) {
).AnyTimes()
s := service.ConnectService{
Eval: eval,
Logger: logger.NewLogger(nil),
Logger: logger.NewLogger(nil, true),
}

if name != "eval returns error" {
Expand Down Expand Up @@ -783,7 +783,7 @@ func BenchmarkConnectService_ResolveObject(b *testing.B) {

s := service.ConnectService{
Eval: eval,
Logger: logger.NewLogger(nil),
Logger: logger.NewLogger(nil, true),
}
if name != "eval returns error" {
outParsed, err := structpb.NewStruct(tt.evalFields.result)
Expand Down
6 changes: 3 additions & 3 deletions pkg/sync/filepath_sync_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -74,7 +74,7 @@ func TestFilePathSync_Notify(t *testing.T) {

fpSync := sync.FilePathSync{
URI: dirName,
Logger: logger.NewLogger(nil),
Logger: logger.NewLogger(nil, true),
}
inotifyChan := make(chan sync.INotify)

Expand Down Expand Up @@ -118,7 +118,7 @@ func TestFilePathSync_Fetch(t *testing.T) {
"success": {
fpSync: sync.FilePathSync{
URI: fmt.Sprintf("%s/%s", dirName, fetchFileName),
Logger: logger.NewLogger(nil),
Logger: logger.NewLogger(nil, true),
},
handleResponse: func(t *testing.T, fetched string, err error) {
if err != nil {
Expand All @@ -133,7 +133,7 @@ func TestFilePathSync_Fetch(t *testing.T) {
"not found": {
fpSync: sync.FilePathSync{
URI: fmt.Sprintf("%s/%s", dirName, "not_found"),
Logger: logger.NewLogger(nil),
Logger: logger.NewLogger(nil, true),
},
handleResponse: func(t *testing.T, fetched string, err error) {
if err == nil {
Expand Down
4 changes: 2 additions & 2 deletions pkg/sync/http_sync_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -105,7 +105,7 @@ func TestHTTPSync_Fetch(t *testing.T) {
Client: mockClient,
BearerToken: tt.bearerToken,
LastBodySHA: tt.lastBodySHA,
Logger: logger.NewLogger(nil),
Logger: logger.NewLogger(nil, true),
}

fetched, err := httpSync.Fetch(context.Background())
Expand Down Expand Up @@ -188,7 +188,7 @@ func TestHTTPSync_Notify(t *testing.T) {
Client: mockClient,
Cron: mockCron,
LastBodySHA: tt.lastBodySHA,
Logger: logger.NewLogger(nil),
Logger: logger.NewLogger(nil, true),
}

go func() {
Expand Down