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

SNOW-625282: Make logrus dependency optional or drop it all together #1286

Open
wants to merge 17 commits into
base: master
Choose a base branch
from
2 changes: 1 addition & 1 deletion auth.go
Original file line number Diff line number Diff line change
Expand Up @@ -354,7 +354,7 @@ func authenticate(
params.Add("roleName", sc.cfg.Role)
}

logger.WithContext(ctx).WithContext(sc.ctx).Infof("PARAMS for Auth: %v, %v, %v, %v, %v, %v",
logger.WithContext(ctx, sc.ctx).Infof("PARAMS for Auth: %v, %v, %v, %v, %v, %v",
params, sc.rest.Protocol, sc.rest.Host, sc.rest.Port, sc.rest.LoginTimeout, sc.cfg.Authenticator.String())

respd, err := sc.rest.FuncPostAuth(ctx, sc.rest, sc.rest.getClientFor(sc.cfg.Authenticator), params, headers, bodyCreator, sc.rest.LoginTimeout)
Expand Down
29 changes: 22 additions & 7 deletions ctx_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -3,8 +3,10 @@
package gosnowflake

import (
"bytes"
"context"
"fmt"
"strings"
"testing"
)

Expand Down Expand Up @@ -38,15 +40,28 @@ func TestCtxVal(t *testing.T) {
}
}

func TestLogEntryCtx(t *testing.T) {
func TestLogCtx(t *testing.T) {
var log = logger
var ctx1 = context.WithValue(context.Background(), SFSessionIDKey, "sessID1")
var ctx2 = context.WithValue(context.Background(), SFSessionUserKey, "admin")

fs1 := context2Fields(ctx1)
fs2 := context2Fields(ctx2)
l1 := log.WithFields(*fs1)
l2 := log.WithFields(*fs2)
l1.Info("Hello 1")
l2.Warning("Hello 2")
var b bytes.Buffer
log.SetOutput(&b)
err := log.SetLogLevel("trace")
if err != nil {
t.Error("could not set log level")
}
l := log.WithContext(ctx1, ctx2)
l.Info("Hello 1")
l.Warn("Hello 2")
s := b.String()
if len(s) <= 0 {
t.Error("nothing written")
}
if !strings.Contains(s, "LOG_SESSION_ID=sessID1") {
t.Error("context ctx1 keys/values not logged")
}
if !strings.Contains(s, "LOG_USER=admin") {
t.Error("context ctx2 keys/values not logged")
}
}
113 changes: 88 additions & 25 deletions log.go
Original file line number Diff line number Diff line change
Expand Up @@ -40,12 +40,59 @@ func RegisterLogContextHook(contextKey string, ctxExtractor ClientLogContextHook
// logger.WithContext is used
var LogKeys = [...]contextKey{SFSessionIDKey, SFSessionUserKey}

// SFLogger Snowflake logger interface to expose FieldLogger defined in logrus
// Fields
Copy link
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Any comment? Why do we need another public var?

Copy link
Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

LogKeys ? It was added in 22Dec20 looks like a convenience for the iteration. At the very least we could make it package local or even fold it into the context2Fields() func, which contains the only use.

Copy link
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

No, I meant Fields :)

Copy link
Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

the Fields type matches the definition of logrus Fields and exists for backward compatibility. I.e. the existing withXXX methods on FieldLogger are;

	WithField(key string, value interface{}) *Entry
	WithFields(fields Fields) *Entry
	WithError(err error) *Entry

so keeping the interfaces as close as possible we have SFLogger containing;

	WithField(key string, value interface{}) LogEntry
	WithFields(fields Fields) LogEntry
	WithError(err error) LogEntry

Copy link
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Ok, so just leave a comment above the var :) Also, if we want to release it as a non compatible change, we don't have to write in a comment that it is a backward compatibility to logrus.

Regardless the variable itself, I see two use cases.

  1. Global map with fields actually global, like instance name/host, OS or app version - that is fine.
  2. WithFields used to propagate fields to the actual log entry. I can't see a good examples, but my intuition says that in some cases it may be helpful, so probably also good to have it.

type Fields map[string]any

// ConvertibleEntry returns the underlying logrus Entry struct.
type ConvertibleEntry interface {
ToEntry() *rlog.Entry
}

// LogEntry allows for logging using a snapshot of field values, similar to logrus.Entry.
// No references to logrus or other implementat specific logging should be placed into this interface.
type LogEntry interface {
Tracef(format string, args ...interface{})
Debugf(format string, args ...interface{})
Infof(format string, args ...interface{})
Printf(format string, args ...interface{})
Warnf(format string, args ...interface{})
Warningf(format string, args ...interface{})
Errorf(format string, args ...interface{})
Fatalf(format string, args ...interface{})
Panicf(format string, args ...interface{})

Trace(args ...interface{})
Debug(args ...interface{})
Info(args ...interface{})
Print(args ...interface{})
Warn(args ...interface{})
Warning(args ...interface{})
Error(args ...interface{})
Fatal(args ...interface{})
Panic(args ...interface{})

Traceln(args ...interface{})
Debugln(args ...interface{})
Infoln(args ...interface{})
Println(args ...interface{})
Warnln(args ...interface{})
Warningln(args ...interface{})
Errorln(args ...interface{})
Fatalln(args ...interface{})
Panicln(args ...interface{})
}

// SFLogger Snowflake logger interface which abstracts away the underlying logging mechanism.
// No references to logrus or other implementat specific logging should be placed into this interface.
type SFLogger interface {
rlog.Ext1FieldLogger
LogEntry
WithField(key string, value interface{}) LogEntry
WithFields(fields Fields) LogEntry
WithError(err error) LogEntry

SetLogLevel(level string) error
GetLogLevel() string
WithContext(ctx context.Context) *rlog.Entry
WithContext(ctx ...context.Context) LogEntry
Copy link
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

It is backward compatible, isn't it? Previously this function returned a struct, now it returns the interface which is implemented by logrus struct, right?

Copy link
Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This is probably the biggest change. Every field in the rlog.Entry struct is exported and modifiable. With a LogEntry you can only emit a log line via trace/debug/info/... .

The rationale behind this change is that ultimately we want to be able to have callers of the driver be able to have full control over the logger and this is only possible when interfaces are exposed, or at the very least its a lot easier.

If we're still looking for a means of exposing the underlying logrus Entry we could ensure that a cast from LogEntry works. I'll wire up a unit test to make sure this is straightforward enough. It doesn't provide 100% code compatibility, but at least it provides an out for anyone that has directly manipulated the logrus Entries.

Copy link
Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Added ConvertibleEntry interface so that callers can convert the underlying LogEntry into a logrus Entry struct. Test case TestLogEntryConversion() shows how to do this.

SetOutput(output io.Writer)
CloseFileOnLoggerReplace(file *os.File) error
Replace(newLogger *SFLogger)
Expand All @@ -56,6 +103,8 @@ func SFCallerPrettyfier(frame *runtime.Frame) (string, string) {
return path.Base(frame.Function), fmt.Sprintf("%s:%d", path.Base(frame.File), frame.Line)
}

var _ SFLogger = &defaultLogger{} // ensure defaultLogger isa SFLogger.

type defaultLogger struct {
inner *rlog.Logger
enabled bool
Expand Down Expand Up @@ -119,9 +168,9 @@ func closeLogFile(file *os.File) {
}

// WithContext return Entry to include fields in context
func (log *defaultLogger) WithContext(ctx context.Context) *rlog.Entry {
fields := context2Fields(ctx)
return log.inner.WithFields(*fields)
func (log *defaultLogger) WithContext(ctxs ...context.Context) LogEntry {
fields := context2Fields(ctxs...)
return log.WithFields(*fields)
}

// CreateDefaultLogger return a new instance of SFLogger with default config
Expand All @@ -132,39 +181,50 @@ func CreateDefaultLogger() SFLogger {
rLogger.SetFormatter(formatter)
rLogger.SetReportCaller(true)
var ret = defaultLogger{inner: rLogger, enabled: true}
return &ret //(&ret).(*SFLogger)
return &ret
}

// WithField allocates a new entry and adds a field to it.
// Debug, Print, Info, Warn, Error, Fatal or Panic must be then applied to
// this new returned entry.
// If you want multiple fields, use `WithFields`.
func (log *defaultLogger) WithField(key string, value interface{}) *rlog.Entry {
return log.inner.WithField(key, value)

func (log *defaultLogger) WithField(key string, value interface{}) LogEntry {
return &entryBridge{log.inner.WithField(key, value)}
}

// Adds a struct of fields to the log entry. All it does is call `WithField` for
// each `Field`.
func (log *defaultLogger) WithFields(fields rlog.Fields) *rlog.Entry {
return log.inner.WithFields(fields)
func (log *defaultLogger) WithFields(fields Fields) LogEntry {
m := map[string]any(fields)
return &entryBridge{log.inner.WithFields(m)}
}

// Add an error as single field to the log entry. All it does is call
// `WithError` for the given `error`.
func (log *defaultLogger) WithError(err error) *rlog.Entry {
return log.inner.WithError(err)
func (log *defaultLogger) WithError(err error) LogEntry {
return &entryBridge{log.inner.WithError(err)}
}

// Overrides the time of the log entry.
func (log *defaultLogger) WithTime(t time.Time) *rlog.Entry {
return log.inner.WithTime(t)
// WithTime overrides the time of the log entry.
func (log *defaultLogger) WithTime(t time.Time) LogEntry {
return &entryBridge{log.inner.WithTime(t)}
}

func (log *defaultLogger) Logf(level rlog.Level, format string, args ...interface{}) {
log.inner.Logf(level, format, args...)
}

var _ LogEntry = &entryBridge{} // ensure entryBridge isa LogEntry.
var _ ConvertibleEntry = &entryBridge{}

type entryBridge struct {
*rlog.Entry
}

func (entry *entryBridge) ToEntry() *rlog.Entry {
return entry.Entry
}

func (log *defaultLogger) Tracef(format string, args ...interface{}) {
if log.enabled {
log.inner.Tracef(format, args...)
Expand Down Expand Up @@ -410,7 +470,6 @@ func (log *defaultLogger) GetLevel() rlog.Level {
// AddHook adds a hook to the logger hooks.
func (log *defaultLogger) AddHook(hook rlog.Hook) {
log.inner.AddHook(hook)

}

// IsLevelEnabled checks if the log level of the logger is greater than the level param
Expand Down Expand Up @@ -442,21 +501,25 @@ func GetLogger() SFLogger {
return logger
}

func context2Fields(ctx context.Context) *rlog.Fields {
var fields = rlog.Fields{}
if ctx == nil {
func context2Fields(ctxs ...context.Context) *Fields {
var fields = Fields{}
if len(ctxs) <= 0 {
return &fields
}

for i := 0; i < len(LogKeys); i++ {
if ctx.Value(LogKeys[i]) != nil {
fields[string(LogKeys[i])] = ctx.Value(LogKeys[i])
for _, ctx := range ctxs {
if ctx.Value(LogKeys[i]) != nil {
fields[string(LogKeys[i])] = ctx.Value(LogKeys[i])
}
}
}

for key, hook := range clientLogContextHooks {
if value := hook(ctx); value != "" {
fields[key] = value
for _, ctx := range ctxs {
if value := hook(ctx); value != "" {
fields[key] = value
}
}
}

Expand Down
31 changes: 29 additions & 2 deletions log_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -14,10 +14,10 @@ import (
rlog "github.com/sirupsen/logrus"
)

func createTestLogger() defaultLogger {
func createTestLogger() *defaultLogger {
var rLogger = rlog.New()
var ret = defaultLogger{inner: rLogger}
return ret
return &ret
}

func TestIsLevelEnabled(t *testing.T) {
Expand All @@ -28,6 +28,17 @@ func TestIsLevelEnabled(t *testing.T) {
}
}

func TestLogLevelEnabled(t *testing.T) {
log := CreateDefaultLogger() // via the SFLogger interface.
err := log.SetLogLevel("info")
if err != nil {
t.Fatalf("log level could not be set %v", err)
}
if log.GetLogLevel() != "info" {
t.Fatalf("log level should be trace but is %v", log.GetLogLevel())
}
}

func TestLogFunction(t *testing.T) {
logger := createTestLogger()
buf := &bytes.Buffer{}
Expand Down Expand Up @@ -340,3 +351,19 @@ func TestLogMaskSecrets(t *testing.T) {
t.Fatalf("expected that password would be masked. WithContext was used, but got: %v", strbuf)
}
}

func TestLogEntryConversion(t *testing.T) {
log := CreateDefaultLogger()
e := log.WithField("k", 1)
l, ok := e.(ConvertibleEntry)
if !ok {
t.Fatalf("expected a ConvertibleEntry")
}
v, ok := l.ToEntry().Data["k"]
if !ok {
t.Fatalf("should be able to access the underlying rlog.Entry")
}
if v.(int) != 1 {
t.Fatalf("expected value to be 1")
}
}
Loading