diff --git a/.github/workflows/godoc.yml b/.github/workflows/godoc.yml new file mode 100644 index 0000000..30a04e2 --- /dev/null +++ b/.github/workflows/godoc.yml @@ -0,0 +1,21 @@ +name: Generate GoDoc + +on: [pull_request] + +jobs: + build: + + runs-on: ubuntu-latest + + steps: + - name: Checkout + uses: actions/checkout@v1 + - name: Generate GoDoc + uses: ktr0731/godoc-action@v0.1.0 + env: + GITHUB_TOKEN: ${{ secrets.GITHUB_TOKEN }} + - name: Push changes + uses: ad-m/github-push-action@master + with: + github_token: ${{ secrets.GITHUB_TOKEN }} + branch: gh-pages diff --git a/log/api.go b/log/api.go index 611128b..252d3fc 100644 --- a/log/api.go +++ b/log/api.go @@ -12,7 +12,7 @@ type Fields struct{ m frozen.Map } // From returns a copied logger from the context that you can use to access logger API. func From(ctx context.Context) Logger { f := getFields(ctx) - return f.getCopiedLogger().(internalLoggerOps).PutFields(f.resolveFields(ctx)) + return f.configureLogger(ctx, f.getCopiedLogger().(fieldSetter)) } // Suppress will ensure that suppressed keys are not logged. @@ -25,6 +25,11 @@ func With(key string, val interface{}) Fields { return Fields{}.With(key, val) } +// WithConfigs adds extra configuration for the logger. +func WithConfigs(configs ...Config) Fields { + return Fields{}.WithConfigs(configs...) +} + // WithCtxRef creates a field with a key that refers to the provided context key, // fields will use key as the fields property and take the value that corresponds // to ctxKey. @@ -83,6 +88,13 @@ func (f Fields) With(key string, val interface{}) Fields { return f.with(key, val) } +// WithConfigs adds extra configuration for the logger. +func (f Fields) WithConfigs(configs ...Config) Fields { + return f.Chain(Fields{ + createConfigMap(configs...), + }) +} + // WithCtxRef adds key and the context key to the fields. func (f Fields) WithCtxRef(key string, ctxKey interface{}) Fields { return f.with(key, ctxRef{ctxKey}) @@ -95,12 +107,14 @@ func (f Fields) WithFunc(key string, val func(context.Context) interface{}) Fiel // WithLogger adds logger which will be used for the log operation. func (f Fields) WithLogger(logger Logger) Fields { - return f.with(loggerKey{}, logger.(internalLoggerOps).Copy()) + return f.with(loggerKey{}, logger.(copyable).Copy()) } // String returns a string that represent the current fields func (f Fields) String(ctx context.Context) string { - return f.resolveFields(ctx).String() + fields := &fieldsCollector{} + f.configureLogger(ctx, fields) + return fields.fields.String() } // MergedString returns a string that represents the current fields merged by fields in context diff --git a/log/api_test.go b/log/api_test.go index fdebc27..51a235d 100644 --- a/log/api_test.go +++ b/log/api_test.go @@ -6,7 +6,6 @@ import ( "testing" "github.com/alecthomas/assert" - "github.com/anz-bank/pkg/log/testutil" "github.com/arr-ai/frozen" "github.com/stretchr/testify/mock" ) @@ -40,6 +39,15 @@ func TestChain(t *testing.T) { assert.True(t, expected.Equal(init.Chain(fields1, fields2, fields3).m)) } +func TestWithConfigsSameConfigType(t *testing.T) { + t.Parallel() + + expectedConfig := frozen.Map{}. + With(standardFormat{}.TypeKey(), standardFormat{}) + f := WithConfigs(NewJSONFormat(), NewStandardFormat()) + assert.True(t, expectedConfig.Equal(f.m)) +} + func TestFrom(t *testing.T) { for _, c := range getUnresolvedFieldsCases() { c := c @@ -59,7 +67,7 @@ func TestFrom(t *testing.T) { } func TestOnto(t *testing.T) { - cases := testutil.GenerateMultipleFieldsCases() + cases := generateMultipleFieldsCases() for _, c := range cases { c := c t.Run(c.Name, func(t *testing.T) { @@ -159,6 +167,10 @@ func TestWithLogger(t *testing.T) { func setLogMockAssertion(logger *mockLogger, fields frozen.Map) { setMockCopyAssertion(logger) + setPutFieldsAssertion(logger, fields) +} + +func setPutFieldsAssertion(logger *mockLogger, fields frozen.Map) { logger.On( "PutFields", mock.MatchedBy( @@ -177,11 +189,11 @@ func getLoggerFromContext(t *testing.T, ctx context.Context) *mockLogger { return m.MustGet(loggerKey{}).(*mockLogger) } -func setMockCopyAssertion(logger *mockLogger) { +func setMockCopyAssertion(logger *mockLogger) *mock.Call { // set to return the same logger for testing purposes, in real case it will return // a copied logger. Tests that use these usually are not checked for their return value // as the return value is mocked - logger.On("Copy").Return(logger) + return logger.On("Copy").Return(logger) } func runFieldsMethod(t *testing.T, empty, nonEmpty func(*testing.T)) { diff --git a/log/benchmark/benchmark_test.go b/log/benchmark/benchmark_test.go index f1a9b1b..57bfde5 100644 --- a/log/benchmark/benchmark_test.go +++ b/log/benchmark/benchmark_test.go @@ -7,7 +7,6 @@ import ( "testing" "github.com/anz-bank/pkg/log" - "github.com/anz-bank/pkg/log/loggers" "github.com/sirupsen/logrus" ) @@ -32,7 +31,7 @@ func BenchmarkLog1000Fields(b *testing.B) { } func BenchmarkWith(b *testing.B) { - logger := loggers.NewNullLogger() + logger := log.NewNullLogger() ctx := log.With("key", "val").With("abc", 123).WithLogger(logger).Onto(context.Background()) for i := 0; i < b.N; i++ { @@ -55,7 +54,7 @@ func BenchmarkLogrus(b *testing.B) { } func BenchmarkLog(b *testing.B) { - logger := loggers.NewNullLogger() + logger := log.NewNullLogger() ctx := log.With("x-user-id", "12344"). With("x-trace-id", "acbdd"). WithLogger(logger). @@ -72,6 +71,6 @@ func runBenchmark(b *testing.B, l int) { for j := 0; j < l; j++ { f = f.With(strconv.Itoa(j), j) } - f.WithLogger(loggers.NewNullLogger()).From(context.Background()).Info("test") + f.WithLogger(log.NewNullLogger()).From(context.Background()).Info("test") } } diff --git a/log/config.go b/log/config.go new file mode 100644 index 0000000..d1ad80a --- /dev/null +++ b/log/config.go @@ -0,0 +1,29 @@ +package log + +type typeKey int + +const Formatter typeKey = iota + +type Config interface { + TypeKey() interface{} + Apply(logger Logger) error +} + +type standardFormat struct{} +type jsonFormat struct{} + +func NewStandardFormat() Config { return standardFormat{} } +func (standardFormat) TypeKey() interface{} { return Formatter } +func (sf standardFormat) Apply(logger Logger) error { + return applyFormatter(sf, logger) +} + +func NewJSONFormat() Config { return jsonFormat{} } +func (jsonFormat) TypeKey() interface{} { return Formatter } +func (jf jsonFormat) Apply(logger Logger) error { + return applyFormatter(jf, logger) +} + +func applyFormatter(formatter Config, logger Logger) error { + return logger.(formattable).SetFormatter(formatter) +} diff --git a/log/examples.md b/log/examples.md index d7ff798..b6cb276 100644 --- a/log/examples.md +++ b/log/examples.md @@ -152,4 +152,40 @@ func loggingDemo(ctx context.Context) { ``` +### Logging in different formats + +You can specify JSON output by adding `WithConfig(NewJSONFormat())`. It will log in the following format: +```js +{ + "fields": { + "key1": "value1", // value can be any data types + "key2": "value2", + }, + "level": "log level", // string, either INFO or DEBUG + "message": "log message", // string, + "timestamp": "log time", // timestamp in RFC3339Nano format +} +``` + +## Configuring logger + +Logger can be configured using the `WithConfig` API and giving it the correct configuration struct. +```go +func configLogDemo(ctx context.Context) { + // Adding configuration can be done by adding the correct struct. Configurations are once again + // treated as fields, which means it will replace old configurations when a configuration + // of the same type is added. For example, if before you added StandardFormatter, calling WithConfig + // with JSONFormatter will replace StandardFormatter. Just like Fields, it will also be stored + // in the context. + ctx = log.WithConfigs(log.NewJSONFormat()).Onto(ctx) + + // You can also have a log-specific configs by not saving it to the context. + log.WithConfigs(log.NewStandardFormat(), log.NewStandardFormat()). + WithLogger(log.NewStandardLogger()). + With("yeet", map[string]interface{}{"foo": "bar", "doesn't": "matter"}). + From(ctx). + Info("json formatted log") +} +``` + Code snippets can be run in the [example file](examples/example.go) diff --git a/log/examples/example.go b/log/examples/example.go index 6a1d6c7..fa1a520 100644 --- a/log/examples/example.go +++ b/log/examples/example.go @@ -5,7 +5,6 @@ import ( "fmt" "github.com/anz-bank/pkg/log" - "github.com/anz-bank/pkg/log/loggers" ) type contextKey struct{} @@ -15,6 +14,7 @@ func main() { ctx := context.Background() fieldsDemo(ctx) loggingDemo(ctx) + configLogDemo(ctx) } func fieldsDemo(ctx context.Context) { @@ -90,7 +90,7 @@ func fieldsDemo(ctx context.Context) { // that logger has been added. Logger is treated as another fields, so you can just chain it // with the WithLogger API. Trying to generate a logger without setting up the logger will make the // program panic. More about logging in another function. - logger1, logger2 := loggers.NewNullLogger(), loggers.NewStandardLogger() + logger1, logger2 := log.NewNullLogger(), log.NewStandardLogger() // Creating a context that contains logger1. ctx = log.WithLogger(logger1).Onto(ctx) @@ -106,7 +106,7 @@ func fieldsDemo(ctx context.Context) { func loggingDemo(ctx context.Context) { // You can choose different loggers or implement your own. // For this example, we are using the standard logger. - logger := loggers.NewStandardLogger() + logger := log.NewStandardLogger() // Adding logger can be done through the WithLogger API. Do not forget to finalize it with // the Onto API if you want the logger to be contained in the context. @@ -118,7 +118,7 @@ func loggingDemo(ctx context.Context) { // the format counterpart, Debugf and Infof. // Logging will log in the following format: // (time in RFC3339Nano Format) (Fields) (Level) (Message) - // Fields themselves are logged as a space separated list of key=value + // Fields themselves are logged as a space separated list of key=value. log.From(ctx).Debug("This does not have any fields") ctx = log.With("this", "one").With("have", "fields").Onto(ctx) @@ -132,3 +132,19 @@ func loggingDemo(ctx context.Context) { log.With("have", "additional fields").With("log-specific", "fields").From(ctx).Debug("log-specific fields") log.From(ctx).Info("context fields are still untouched as long as the context is unchanged") } + +func configLogDemo(ctx context.Context) { + // Adding configuration can be done by adding the correct struct. Configurations are once again + // treated as fields, which means it will replace old configurations when a configuration + // of the same type is added. For example, if before you added StandardFormatter, calling WithConfig + // with JSONFormatter will replace StandardFormatter. Just like Fields, it will also be stored + // in the context. + ctx = log.WithConfigs(log.NewJSONFormat()).Onto(ctx) + + // You can also have a log-specific configs by not saving it to the context. + log.WithConfigs(log.NewStandardFormat(), log.NewStandardFormat()). + WithLogger(log.NewStandardLogger()). + With("yeet", map[string]interface{}{"foo": "bar", "doesn't": "matter"}). + From(ctx). + Info("json formatted log") +} diff --git a/log/loggerInterface.go b/log/loggerInterface.go index 6f2654a..64f55c5 100644 --- a/log/loggerInterface.go +++ b/log/loggerInterface.go @@ -14,9 +14,17 @@ type Logger interface { Infof(format string, args ...interface{}) } -type internalLoggerOps interface { - // PutFields returns the Logger with the new fields added - PutFields(fields frozen.Map) Logger +type copyable interface { // Copy returns a logger whose data is copied from the caller Copy() Logger } + +type fieldSetter interface { + // PutFields returns the Logger with the new fields added + PutFields(fields frozen.Map) Logger +} + +type formattable interface { + // SetFormatter sets the formatter for the logger + SetFormatter(formatter Config) error +} diff --git a/log/loggers/standardLogger.go b/log/loggers/standardLogger.go deleted file mode 100644 index 2454665..0000000 --- a/log/loggers/standardLogger.go +++ /dev/null @@ -1,109 +0,0 @@ -package loggers - -import ( - "fmt" - "os" - "strings" - "time" - - "github.com/anz-bank/pkg/log" - "github.com/arr-ai/frozen" - "github.com/sirupsen/logrus" -) - -const keyFields = "_fields" - -type standardLogger struct { - internal *logrus.Logger - fields frozen.Map -} - -type standardFormat struct{} - -func (sf *standardFormat) Format(entry *logrus.Entry) ([]byte, error) { - message := strings.Builder{} - message.WriteString(entry.Time.Format(time.RFC3339Nano)) - message.WriteByte(' ') - - if entry.Data[keyFields] != "" { - message.WriteString(entry.Data[keyFields].(string)) - message.WriteByte(' ') - } - - message.WriteString(strings.ToUpper(entry.Level.String())) - message.WriteByte(' ') - - if entry.Message != "" { - message.WriteString(entry.Message) - message.WriteByte(' ') - } - - // TODO: add codelinker's message here - message.WriteByte('\n') - return []byte(message.String()), nil -} - -// NewStandardLogger returns a logger with logrus standard logger as the internal logger -func NewStandardLogger() log.Logger { - return &standardLogger{internal: setupStandardLogger()} -} - -func (sl *standardLogger) Debug(args ...interface{}) { - sl.setInfo().Debug(args...) -} - -func (sl *standardLogger) Debugf(format string, args ...interface{}) { - sl.setInfo().Debugf(format, args...) -} - -func (sl *standardLogger) Info(args ...interface{}) { - sl.setInfo().Info(args...) -} - -func (sl *standardLogger) Infof(format string, args ...interface{}) { - sl.setInfo().Infof(format, args...) -} - -func (sl *standardLogger) PutFields(fields frozen.Map) log.Logger { - sl.fields = fields - return sl -} - -func (sl *standardLogger) Copy() log.Logger { - return &standardLogger{setupStandardLogger(), sl.fields} -} - -func (sl *standardLogger) setInfo() *logrus.Entry { - // TODO: set linker here - return sl.internal.WithFields(logrus.Fields{ - keyFields: sl.getFormattedField(), - }) -} - -func (sl *standardLogger) getFormattedField() string { - if sl.fields.Count() == 0 { - return "" - } - - fields := strings.Builder{} - i := sl.fields.Range() - i.Next() - fields.WriteString(fmt.Sprintf("%v=%v", i.Key(), i.Value())) - for i.Next() { - fields.WriteString(fmt.Sprintf(" %v=%v", i.Key(), i.Value())) - } - return fields.String() -} - -func setupStandardLogger() *logrus.Logger { - logger := logrus.New() - logger.SetFormatter(&standardFormat{}) - - // makes sure that it always logs every level - logger.SetLevel(logrus.DebugLevel) - - // explicitly set it to os.Stderr - logger.SetOutput(os.Stderr) - - return logger -} diff --git a/log/loggers/standardLogger_test.go b/log/loggers/standardLogger_test.go deleted file mode 100644 index 3ec23d0..0000000 --- a/log/loggers/standardLogger_test.go +++ /dev/null @@ -1,143 +0,0 @@ -package loggers - -import ( - "strings" - "testing" - - "github.com/anz-bank/pkg/log/testutil" - "github.com/arr-ai/frozen" - "github.com/sirupsen/logrus" - "github.com/stretchr/testify/assert" - "github.com/stretchr/testify/require" -) - -const ( - testMessage = "This is a test message" - simpleFormat = "%s" -) - -// to test fields output for all log -var testField = testutil.GenerateMultipleFieldsCases()[0].Fields - -func TestCopyStandardLogger(t *testing.T) { - t.Parallel() - - logger := getNewStandardLogger().PutFields( - frozen.NewMap( - frozen.KV("numberVal", 1), - frozen.KV("byteVal", 'k'), - frozen.KV("stringVal", "this is a sentence"), - ), - ).(*standardLogger) - copiedLogger := logger.Copy().(*standardLogger) - assert.NotEqual(t, logger.internal, copiedLogger.internal) - assert.True(t, logger.fields.Equal(copiedLogger.fields)) - assert.True(t, logger != copiedLogger) -} - -func TestDebug(t *testing.T) { - testLogOutput(t, logrus.DebugLevel, frozen.NewMap(), func() { - NewStandardLogger().Debug(testMessage) - }) - - testLogOutput(t, logrus.DebugLevel, testField, func() { - getStandardLoggerWithFields().Debug(testMessage) - }) -} - -func TestDebugf(t *testing.T) { - testLogOutput(t, logrus.DebugLevel, frozen.NewMap(), func() { - NewStandardLogger().Debugf(simpleFormat, testMessage) - }) - - testLogOutput(t, logrus.DebugLevel, testField, func() { - getStandardLoggerWithFields().Debugf(simpleFormat, testMessage) - }) -} - -func TestInfo(t *testing.T) { - testLogOutput(t, logrus.InfoLevel, frozen.NewMap(), func() { - NewStandardLogger().Info(testMessage) - }) - - testLogOutput(t, logrus.InfoLevel, testField, func() { - getStandardLoggerWithFields().Info(testMessage) - }) -} - -func TestInfof(t *testing.T) { - testLogOutput(t, logrus.InfoLevel, frozen.NewMap(), func() { - NewStandardLogger().Infof(simpleFormat, testMessage) - }) - - testLogOutput(t, logrus.InfoLevel, testField, func() { - getStandardLoggerWithFields().Infof(simpleFormat, testMessage) - }) -} - -func testLogOutput(t *testing.T, level logrus.Level, fields frozen.Map, logFunc func()) { - expectedOutput := strings.Join([]string{strings.ToUpper(level.String()), testMessage}, " ") - actualOutput := testutil.RedirectOutput(t, logFunc) - - // uses Contains to avoid checking timestamps and fields - assert.Contains(t, actualOutput, expectedOutput) -} - -func TestNewStandardLogger(t *testing.T) { - t.Parallel() - - logger := NewStandardLogger() - - require.NotNil(t, logger) - assert.IsType(t, logger, &standardLogger{}) -} - -func TestGetFormattedFieldEmptyFields(t *testing.T) { - t.Parallel() - - require.Equal(t, getNewStandardLogger().getFormattedField(), "") -} - -func TestGetFormattedFieldWithFields(t *testing.T) { - t.Parallel() - - logger := getNewStandardLogger().PutFields( - frozen.NewMap( - frozen.KV("numberVal", 1), - frozen.KV("byteVal", 'k'), - frozen.KV("stringVal", "this is a sentence"), - ), - ).(*standardLogger) - // fields are in a random order - expectedFields := []string{"byteVal=107", "numberVal=1", "stringVal=this is a sentence"} - actualFields := logger.getFormattedField() - for _, e := range expectedFields { - assert.Contains(t, actualFields, e) - } -} - -func TestPutFields(t *testing.T) { - t.Parallel() - - cases := testutil.GenerateMultipleFieldsCases() - for _, c := range cases { - c := c - t.Run(c.Name, - func(t *testing.T) { - t.Parallel() - - logger := getNewStandardLogger() - logger.PutFields(c.Fields) - assert.True(t, c.Fields.Equal(logger.fields)) - }) - } -} - -func getNewStandardLogger() *standardLogger { - return NewStandardLogger().(*standardLogger) -} - -func getStandardLoggerWithFields() *standardLogger { - logger := getNewStandardLogger().PutFields(testField) - return logger.(*standardLogger) -} diff --git a/log/mockLogger.go b/log/mockLogger.go index 51a4825..bdeea49 100644 --- a/log/mockLogger.go +++ b/log/mockLogger.go @@ -37,3 +37,7 @@ func (m *mockLogger) PutFields(fields frozen.Map) Logger { func (m *mockLogger) Copy() Logger { return m.Called().Get(0).(Logger) } + +func (m *mockLogger) SetFormatter(formatter Config) error { + return m.Called(formatter).Error(0) +} diff --git a/log/loggers/nullLogger.go b/log/nullLogger.go similarity index 71% rename from log/loggers/nullLogger.go rename to log/nullLogger.go index 007420f..d5f796d 100644 --- a/log/loggers/nullLogger.go +++ b/log/nullLogger.go @@ -1,9 +1,8 @@ -package loggers +package log import ( "bytes" - "github.com/anz-bank/pkg/log" "github.com/arr-ai/frozen" ) @@ -11,7 +10,8 @@ type nullLogger struct { internal *standardLogger } -func NewNullLogger() log.Logger { +// Create a null logger that outputs to a buffer, for benchmarking +func NewNullLogger() Logger { return &nullLogger{internal: setUpLogger()} } @@ -31,17 +31,21 @@ func (n *nullLogger) Infof(format string, args ...interface{}) { n.internal.Infof(format, args...) } -func (n *nullLogger) PutFields(fields frozen.Map) log.Logger { +func (n *nullLogger) PutFields(fields frozen.Map) Logger { n.internal.fields = fields return n } -func (n *nullLogger) Copy() log.Logger { +func (n *nullLogger) Copy() Logger { return &nullLogger{ setUpLogger().PutFields(n.internal.fields).(*standardLogger), } } +func (n *nullLogger) SetFormatter(formatter Config) error { + return n.internal.SetFormatter(formatter) +} + func setUpLogger() *standardLogger { logger := NewStandardLogger().(*standardLogger) logger.internal.SetOutput(&bytes.Buffer{}) diff --git a/log/standardLogger.go b/log/standardLogger.go new file mode 100644 index 0000000..8980657 --- /dev/null +++ b/log/standardLogger.go @@ -0,0 +1,141 @@ +package log + +import ( + "encoding/json" + "errors" + "fmt" + "os" + "strings" + "time" + + "github.com/arr-ai/frozen" + "github.com/sirupsen/logrus" +) + +const keyFields = "_fields" + +type standardLogger struct { + internal *logrus.Logger + fields frozen.Map +} + +func (sf standardFormat) Format(entry *logrus.Entry) ([]byte, error) { + message := strings.Builder{} + message.WriteString(entry.Time.Format(time.RFC3339Nano)) + message.WriteByte(' ') + + if entry.Data[keyFields] != nil && entry.Data[keyFields].(frozen.Map).Count() != 0 { + message.WriteString(getFormattedField(entry.Data[keyFields].(frozen.Map))) + message.WriteByte(' ') + } + + message.WriteString(strings.ToUpper(entry.Level.String())) + message.WriteByte(' ') + + if entry.Message != "" { + message.WriteString(entry.Message) + message.WriteByte(' ') + } + + // TODO: add codelinker's message here + message.WriteByte('\n') + return []byte(message.String()), nil +} + +func (jf jsonFormat) Format(entry *logrus.Entry) ([]byte, error) { + jsonFile := make(map[string]interface{}) + jsonFile["timestamp"] = entry.Time.Format(time.RFC3339Nano) + jsonFile["message"] = entry.Message + jsonFile["level"] = strings.ToUpper(entry.Level.String()) + if entry.Data[keyFields] != nil && entry.Data[keyFields].(frozen.Map).Count() != 0 { + fields := make(map[string]interface{}) + for i := entry.Data[keyFields].(frozen.Map).Range(); i.Next(); { + fields[i.Key().(string)] = i.Value() + } + jsonFile["fields"] = fields + } + data, err := json.Marshal(jsonFile) + if err != nil { + return nil, err + } + return append(data, '\n'), err +} + +// NewStandardLogger returns a logger with logrus standard logger as the internal logger +func NewStandardLogger() Logger { + logger := logrus.New() + logger.SetFormatter(&standardFormat{}) + + // makes sure that it always logs every level + logger.SetLevel(logrus.DebugLevel) + + // explicitly set it to os.Stderr + logger.SetOutput(os.Stderr) + + return &standardLogger{internal: logger} +} + +func (sl *standardLogger) Debug(args ...interface{}) { + sl.setInfo().Debug(args...) +} + +func (sl *standardLogger) Debugf(format string, args ...interface{}) { + sl.setInfo().Debugf(format, args...) +} + +func (sl *standardLogger) Info(args ...interface{}) { + sl.setInfo().Info(args...) +} + +func (sl *standardLogger) Infof(format string, args ...interface{}) { + sl.setInfo().Infof(format, args...) +} + +func (sl *standardLogger) PutFields(fields frozen.Map) Logger { + sl.fields = fields + return sl +} + +func (sl *standardLogger) SetFormatter(formatter Config) error { + logrusFormatter, isLogrusFormatter := formatter.(logrus.Formatter) + if !isLogrusFormatter { + return errors.New("formatter is not logrus formatter type") + } + sl.internal.SetFormatter(logrusFormatter) + return nil +} + +func (sl *standardLogger) Copy() Logger { + return &standardLogger{sl.getCopiedInternalLogger(), sl.fields} +} + +func (sl *standardLogger) setInfo() *logrus.Entry { + // TODO: set linker here + return sl.internal.WithFields(logrus.Fields{ + keyFields: sl.fields, + }) +} + +func getFormattedField(fields frozen.Map) string { + if fields.Count() == 0 { + return "" + } + + formattedFields := strings.Builder{} + i := fields.Range() + i.Next() + formattedFields.WriteString(fmt.Sprintf("%v=%v", i.Key(), i.Value())) + for i.Next() { + formattedFields.WriteString(fmt.Sprintf(" %v=%v", i.Key(), i.Value())) + } + return formattedFields.String() +} + +func (sl *standardLogger) getCopiedInternalLogger() *logrus.Logger { + logger := logrus.New() + logger.SetFormatter(sl.internal.Formatter) + logger.SetLevel(sl.internal.Level) + logger.SetOutput(sl.internal.Out) + + return logger +} diff --git a/log/standardLogger_test.go b/log/standardLogger_test.go new file mode 100644 index 0000000..aaa3cab --- /dev/null +++ b/log/standardLogger_test.go @@ -0,0 +1,205 @@ +package log + +import ( + "encoding/json" + "strings" + "testing" + + "github.com/arr-ai/frozen" + "github.com/sirupsen/logrus" + "github.com/stretchr/testify/assert" + "github.com/stretchr/testify/require" +) + +const ( + testMessage = "This is a test message" + simpleFormat = "%s" +) + +// to test fields output for all log +var testField = generateMultipleFieldsCases()[0].Fields + +func TestCopyStandardLogger(t *testing.T) { + t.Parallel() + + logger := getNewStandardLogger().PutFields( + frozen.NewMap( + frozen.KV("numberVal", 1), + frozen.KV("byteVal", 'k'), + frozen.KV("stringVal", "this is a sentence"), + ), + ).(*standardLogger) + copiedLogger := logger.Copy().(*standardLogger) + assert.NotEqual(t, logger.internal, copiedLogger.internal) + assert.True(t, logger.fields.Equal(copiedLogger.fields)) + assert.True(t, logger != copiedLogger) +} + +func TestDebug(t *testing.T) { + testStandardLogOutput(t, logrus.DebugLevel, frozen.NewMap(), func() { + NewStandardLogger().Debug(testMessage) + }) + + testJSONLogOutput(t, logrus.DebugLevel, frozen.NewMap(), func() { + logger := getNewStandardLogger() + require.NoError(t, logger.SetFormatter(NewJSONFormat())) + logger.Debug(testMessage) + }) + + testStandardLogOutput(t, logrus.DebugLevel, testField, func() { + getStandardLoggerWithFields().Debug(testMessage) + }) + + testJSONLogOutput(t, logrus.DebugLevel, testField, func() { + logger := getStandardLoggerWithFields() + require.NoError(t, logger.SetFormatter(NewJSONFormat())) + logger.Debug(testMessage) + }) +} + +func TestDebugf(t *testing.T) { + testStandardLogOutput(t, logrus.DebugLevel, frozen.NewMap(), func() { + NewStandardLogger().Debugf(simpleFormat, testMessage) + }) + + testJSONLogOutput(t, logrus.DebugLevel, frozen.NewMap(), func() { + logger := getNewStandardLogger() + require.NoError(t, logger.SetFormatter(NewJSONFormat())) + logger.Debugf(simpleFormat, testMessage) + }) + + testStandardLogOutput(t, logrus.DebugLevel, testField, func() { + getStandardLoggerWithFields().Debugf(simpleFormat, testMessage) + }) + + testJSONLogOutput(t, logrus.DebugLevel, testField, func() { + logger := getStandardLoggerWithFields() + require.NoError(t, logger.SetFormatter(NewJSONFormat())) + logger.Debugf(simpleFormat, testMessage) + }) +} + +func TestInfo(t *testing.T) { + testStandardLogOutput(t, logrus.InfoLevel, frozen.NewMap(), func() { + NewStandardLogger().Info(testMessage) + }) + + testJSONLogOutput(t, logrus.InfoLevel, frozen.NewMap(), func() { + logger := getNewStandardLogger() + require.NoError(t, logger.SetFormatter(NewJSONFormat())) + logger.Info(testMessage) + }) + + testStandardLogOutput(t, logrus.InfoLevel, testField, func() { + getStandardLoggerWithFields().Info(testMessage) + }) + + testJSONLogOutput(t, logrus.InfoLevel, testField, func() { + logger := getStandardLoggerWithFields() + require.NoError(t, logger.SetFormatter(NewJSONFormat())) + logger.Info(testMessage) + }) +} + +func TestInfof(t *testing.T) { + testStandardLogOutput(t, logrus.InfoLevel, frozen.NewMap(), func() { + NewStandardLogger().Infof(simpleFormat, testMessage) + }) + + testJSONLogOutput(t, logrus.InfoLevel, frozen.NewMap(), func() { + logger := getNewStandardLogger() + require.NoError(t, logger.SetFormatter(NewJSONFormat())) + logger.Infof(simpleFormat, testMessage) + }) + + testStandardLogOutput(t, logrus.InfoLevel, testField, func() { + getStandardLoggerWithFields().Infof(simpleFormat, testMessage) + }) + + testJSONLogOutput(t, logrus.InfoLevel, testField, func() { + logger := getStandardLoggerWithFields() + require.NoError(t, logger.SetFormatter(NewJSONFormat())) + logger.Infof(simpleFormat, testMessage) + }) +} + +func testStandardLogOutput(t *testing.T, level logrus.Level, fields frozen.Map, logFunc func()) { + expectedOutput := strings.Join([]string{strings.ToUpper(level.String()), testMessage}, " ") + actualOutput := redirectOutput(t, logFunc) + + // uses Contains to avoid checking timestamps and fields + assert.Contains(t, actualOutput, expectedOutput) +} + +func testJSONLogOutput(t *testing.T, level logrus.Level, fields frozen.Map, logFunc func()) { + out := make(map[string]interface{}) + require.NoError(t, json.Unmarshal([]byte(redirectOutput(t, logFunc)), &out)) + assert.Equal(t, out["message"], testMessage) + assert.Equal(t, out["level"], strings.ToUpper(level.String())) + if fields.Count() != 0 { + // type correction because json unmarshall reads numbers as float64 + assert.Equal(t, + convertToGoMap(fields.With("byte", float64('1')).With("int", float64(123))), + out["fields"].(map[string]interface{}), + ) + } +} + +func TestNewStandardLogger(t *testing.T) { + t.Parallel() + + logger := NewStandardLogger() + + require.NotNil(t, logger) + assert.IsType(t, logger, &standardLogger{}) +} + +func TestGetFormattedFieldEmptyFields(t *testing.T) { + t.Parallel() + + require.Equal(t, "", getFormattedField(getNewStandardLogger().fields)) +} + +func TestGetFormattedFieldWithFields(t *testing.T) { + t.Parallel() + + logger := getNewStandardLogger().PutFields( + frozen.NewMap( + frozen.KV("numberVal", 1), + frozen.KV("byteVal", 'k'), + frozen.KV("stringVal", "this is a sentence"), + ), + ).(*standardLogger) + // fields are in a random order + expectedFields := []string{"byteVal=107", "numberVal=1", "stringVal=this is a sentence"} + actualFields := getFormattedField(logger.fields) + for _, e := range expectedFields { + assert.Contains(t, actualFields, e) + } +} + +func TestPutFields(t *testing.T) { + t.Parallel() + + cases := generateMultipleFieldsCases() + for _, c := range cases { + c := c + t.Run(c.Name, + func(t *testing.T) { + t.Parallel() + + logger := getNewStandardLogger() + logger.PutFields(c.Fields) + assert.True(t, c.Fields.Equal(logger.fields)) + }) + } +} + +func getNewStandardLogger() *standardLogger { + return NewStandardLogger().(*standardLogger) +} + +func getStandardLoggerWithFields() *standardLogger { + logger := getNewStandardLogger().PutFields(testField) + return logger.(*standardLogger) +} diff --git a/log/testutil/testutil.go b/log/testutil.go similarity index 53% rename from log/testutil/testutil.go rename to log/testutil.go index e30e300..dbac4be 100644 --- a/log/testutil/testutil.go +++ b/log/testutil.go @@ -1,25 +1,22 @@ -package testutil +package log import ( "bytes" - "fmt" "io" "os" - "sort" - "strings" "testing" "github.com/arr-ai/frozen" "github.com/stretchr/testify/require" ) -type MultipleFields struct { +type multipleFields struct { Name string Fields, GlobalFields frozen.Map } -func GenerateMultipleFieldsCases() []MultipleFields { - return []MultipleFields{ +func generateMultipleFieldsCases() []multipleFields { + return []multipleFields{ { Name: "Multiple types of Values", Fields: frozen.NewMap( @@ -40,7 +37,7 @@ func GenerateMultipleFieldsCases() []MultipleFields { } // Adapted from https://stackoverflow.com/questions/10473800/in-go-how-do-i-capture-stdout-of-a-function-into-a-string -func RedirectOutput(t *testing.T, print func()) string { +func redirectOutput(t *testing.T, print func()) string { old := os.Stderr r, w, err := os.Pipe() require.NoError(t, err) @@ -61,36 +58,10 @@ func RedirectOutput(t *testing.T, print func()) string { return <-outC } -func OutputFormattedFields(fields frozen.Map) string { - if fields.Count() == 0 { - return "" - } - - keys := make([]string, fields.Count()) - index := 0 - for k := fields.Range(); k.Next(); { - keys[index] = k.Key().(string) - index++ - } - - sort.Strings(keys) - - output := strings.Builder{} - output.WriteString(fmt.Sprintf("%s=%v", keys[0], fields.MustGet(keys[0]))) - - if fields.Count() > 1 { - for _, keyField := range keys[1:] { - output.WriteString(fmt.Sprintf(" %s=%v", keyField, fields.MustGet(keyField))) - } - } - - return output.String() -} - -func ConvertToGoMap(fields frozen.Map) map[interface{}]interface{} { - goMap := make(map[interface{}]interface{}) +func convertToGoMap(fields frozen.Map) map[string]interface{} { + goMap := make(map[string]interface{}) for i := fields.Range(); i.Next(); { - goMap[i.Key()] = i.Value() + goMap[i.Key().(string)] = i.Value() } return goMap } diff --git a/log/util.go b/log/util.go index 9734842..c9b6791 100644 --- a/log/util.go +++ b/log/util.go @@ -11,15 +11,24 @@ type loggerKey struct{} type suppress struct{} type ctxRef struct{ ctxKey interface{} } +type fieldsCollector struct { + fields frozen.Map +} + +func (f *fieldsCollector) PutFields(fields frozen.Map) Logger { + f.fields = fields + return NewNullLogger() +} + func (f Fields) getCopiedLogger() Logger { logger, exists := f.m.Get(loggerKey{}) if !exists { panic("Logger has not been added") } - return logger.(internalLoggerOps).Copy() + return logger.(copyable).Copy() } -func (f Fields) resolveFields(ctx context.Context) frozen.Map { +func (f Fields) configureLogger(ctx context.Context, logger fieldSetter) Logger { fields := f.m var toSuppress frozen.SetBuilder toSuppress.Add(loggerKey{}) @@ -39,9 +48,16 @@ func (f Fields) resolveFields(ctx context.Context) frozen.Map { } case suppress: toSuppress.Add(i.Key()) + case Config: + toSuppress.Add(i.Key()) + err := k.Apply(logger.(Logger)) + if err != nil { + //TODO: should decide whether it should panic or not + panic(err) + } } } - return fields.Without(toSuppress.Finish()) + return logger.PutFields(fields.Without(toSuppress.Finish())) } func (f Fields) with(key, val interface{}) Fields { @@ -55,3 +71,11 @@ func getFields(ctx context.Context) Fields { } return Fields{fields} } + +func createConfigMap(configs ...Config) frozen.Map { + var mb frozen.MapBuilder + for _, c := range configs { + mb.Put(c.TypeKey(), c) + } + return mb.Finish() +} diff --git a/log/util_test.go b/log/util_test.go index e1dda8b..24b3798 100644 --- a/log/util_test.go +++ b/log/util_test.go @@ -4,7 +4,6 @@ import ( "context" "testing" - "github.com/alecthomas/assert" "github.com/arr-ai/frozen" ) @@ -64,18 +63,41 @@ func getUnresolvedFieldsCases() []fieldsTest { } } -func TestResolveFields(t *testing.T) { +func TestConfigureLogger(t *testing.T) { for _, c := range getUnresolvedFieldsCases() { c := c t.Run(c.name, func(t *testing.T) { t.Parallel() + logger := newMockLogger() + setPutFieldsAssertion(logger, c.expected) ctx := context.Background() for i := c.contextFields.Range(); i.Next(); { ctx = context.WithValue(ctx, i.Key(), i.Value()) } - - assert.True(t, c.expected.Equal(Fields{c.unresolveds}.resolveFields(ctx))) + Fields{c.unresolveds}.configureLogger(ctx, Logger(logger).(fieldSetter)) + logger.AssertExpectations(t) }) } } + +func TestConfigureLoggerWithConfigs(t *testing.T) { + t.Parallel() + + //TODO: add more configs + testCase := getUnresolvedFieldsCases()[0] + unresolveds := Fields{testCase.unresolveds}.WithConfigs(NewJSONFormat()) + expected := testCase.expected + + logger := newMockLogger() + setPutFieldsAssertion(logger, expected) + logger.On("SetFormatter", NewJSONFormat()).Return(nil) + + ctx := context.Background() + for i := testCase.contextFields.Range(); i.Next(); { + ctx = context.WithValue(ctx, i.Key(), i.Value()) + } + + unresolveds.configureLogger(ctx, Logger(logger).(fieldSetter)) + logger.AssertExpectations(t) +}