diff options
author | Jonathan <jonfritz@gmail.com> | 2017-08-31 15:59:03 -0400 |
---|---|---|
committer | GitHub <noreply@github.com> | 2017-08-31 15:59:03 -0400 |
commit | 74b5e52c4eb54000dcb5a7b46c0977d732bce80f (patch) | |
tree | b8b985cadb630879763ddb48777e4ed2714ac0c0 /utils/logger/logger_test.go | |
parent | 000d7aad3d31c5e590db5812f7f8500856e11985 (diff) | |
download | chat-74b5e52c4eb54000dcb5a7b46c0977d732bce80f.tar.gz chat-74b5e52c4eb54000dcb5a7b46c0977d732bce80f.tar.bz2 chat-74b5e52c4eb54000dcb5a7b46c0977d732bce80f.zip |
PLT-3893: Structured Logging Continues (#7252)
* PLT-3893: Imported logger work from https://github.com/MusikPolice/platform
* PLT-3893: Integrated logger with system config
* PLT-3893: Integrated Mattermost config with logging solution, modified log message serialization so entire message is serialized as a JSON object
* PLT-3893: Added support for format strings in Debug methods. Added an overload that does not require a Context object for cases when one isn't available
* PLT-3893: Added context and format string support to debug and error methods
* PLT-3893: A few updates from pull request feedback
* PLT-3893: Changed tests to use testify
* Fixed TestAddRemoveConfigListener to no longer assume that there are zero config listeners when the test begins, since other tests could add config listeners
* Updated TestGetDeletedChannelsForTeam so that it doesn't assume state when it begins
* PLT-3893: Changed File property of log message so that it's relative to /mattermost directory, rather than to wherever the user is running the application from on their machine
* Flipped expected/actual assert arguments, added an explicit test for getCallerFilename(...), since it's failing on Jenkins
* Added printlns to debug failing tests on Jenkins
* Relaxed test cases to avoid failure on Jenkins caused by code coverage calculations. Removed printlns.
* Changed the way that caller filename is determined to make it more robust, updated tests to make them more lax, while not choking on the strange paths that Jenkins uses.
* Fixed gofmt issues
* Added debug output to tests to diagnose Jenkins build failures
* Still trying to get some useful debug logging on Jenkins
* Changed getCallerFilename to handle the strange paths that runtime.Caller(...) returns on Jenkins
* Fixing checkstyle issues
Diffstat (limited to 'utils/logger/logger_test.go')
-rw-r--r-- | utils/logger/logger_test.go | 287 |
1 files changed, 287 insertions, 0 deletions
diff --git a/utils/logger/logger_test.go b/utils/logger/logger_test.go new file mode 100644 index 000000000..d7ef9237c --- /dev/null +++ b/utils/logger/logger_test.go @@ -0,0 +1,287 @@ +// this is a new logger interface for mattermost + +package logger + +import ( + "context" + "encoding/json" + "errors" + "fmt" + "regexp" + "testing" + + "github.com/stretchr/testify/assert" + "github.com/stretchr/testify/require" +) + +type LogMessage struct { + Context map[string]string + File string + Message string +} + +const validPath = `^utils/([a-z_]+/)*logger_test.go$` + +// ensures that the relative path of the file that called into the logger is returned +func TestGetCallerFilename(t *testing.T) { + filename, _ := getCallerFilename() + matched, err := regexp.MatchString(validPath, filename) + require.NoError(t, err) + assert.True(t, matched) +} + +// ensures that values can be recorded on a Context object, and that the data in question is serialized as a part of the log message +func TestSerializeContext(t *testing.T) { + ctx := context.Background() + + expectedUserId := "some-fake-user-id" + ctx = WithUserId(ctx, expectedUserId) + + expectedRequestId := "some-fake-request-id" + ctx = WithRequestId(ctx, expectedRequestId) + + serialized := serializeContext(ctx) + + assert.Equal(t, map[string]string{ + "user_id": expectedUserId, + "request_id": expectedRequestId, + }, serialized) +} + +// ensures that an entire log message with an empty context can be properly serialized into a JSON object +func TestSerializeLogMessageEmptyContext(t *testing.T) { + emptyContext := context.Background() + + var logMessage = "This is a log message" + var serialized = serializeLogMessage(emptyContext, logMessage) + + var deserialized LogMessage + json.Unmarshal([]byte(serialized), &deserialized) + + assert.Empty(t, deserialized.Context) + assert.Equal(t, logMessage, deserialized.Message) + matched, err := regexp.MatchString(validPath, deserialized.File) + require.NoError(t, err) + assert.True(t, matched) +} + +// ensures that an entire log message with a populated context can be properly serialized into a JSON object +func TestSerializeLogMessagePopulatedContext(t *testing.T) { + populatedContext := context.Background() + + populatedContext = WithRequestId(populatedContext, "foo") + populatedContext = WithUserId(populatedContext, "bar") + + var logMessage = "This is a log message" + var serialized = serializeLogMessage(populatedContext, logMessage) + + var deserialized LogMessage + json.Unmarshal([]byte(serialized), &deserialized) + + assert.Equal(t, map[string]string{ + "request_id": "foo", + "user_id": "bar", + }, deserialized.Context) + assert.Equal(t, logMessage, deserialized.Message) + matched, err := regexp.MatchString(validPath, deserialized.File) + require.NoError(t, err) + assert.True(t, matched) +} + +// ensures that a debugLog message is passed through to the underlying logger as expected +func TestDebugc(t *testing.T) { + // inject a "mocked" debugLog method that captures the first argument that is passed to it + var capture string + oldDebug := debugLog + defer func() { debugLog = oldDebug }() + type WrapperType func() string + debugLog = func(format interface{}, args ...interface{}) { + // the code that we're testing passes a closure to the debugLog method, so we have to execute it to get the actual message back + if f, ok := format.(func() string); ok { + capture = WrapperType(f)() + } else { + t.Error("First parameter passed to Debug is not a closure") + } + } + + // log something + emptyContext := context.Background() + var logMessage = "Some log message" + Debugc(emptyContext, logMessage) + + // check to see that the message is logged to the underlying log system, in this case our mock method + var deserialized LogMessage + json.Unmarshal([]byte(capture), &deserialized) + + assert.Empty(t, deserialized.Context) + assert.Equal(t, logMessage, deserialized.Message) + matched, err := regexp.MatchString(validPath, deserialized.File) + require.NoError(t, err) + assert.True(t, matched) +} + +// ensures that a debugLog message is passed through to the underlying logger as expected +func TestDebugf(t *testing.T) { + // inject a "mocked" debugLog method that captures the first argument that is passed to it + var capture string + oldDebug := debugLog + defer func() { debugLog = oldDebug }() + type WrapperType func() string + debugLog = func(format interface{}, args ...interface{}) { + // the code that we're testing passes a closure to the debugLog method, so we have to execute it to get the actual message back + if f, ok := format.(func() string); ok { + capture = WrapperType(f)() + } else { + t.Error("First parameter passed to Debug is not a closure") + } + } + + // log something + formatString := "Some %v message" + param := "log" + Debugf(formatString, param) + + // check to see that the message is logged to the underlying log system, in this case our mock method + var deserialized LogMessage + json.Unmarshal([]byte(capture), &deserialized) + + assert.Empty(t, deserialized.Context) + assert.Equal(t, fmt.Sprintf(formatString, param), deserialized.Message) + matched, err := regexp.MatchString(validPath, deserialized.File) + require.NoError(t, err) + assert.True(t, matched) +} + +// ensures that an infoLog message is passed through to the underlying logger as expected +func TestInfoc(t *testing.T) { + // inject a "mocked" infoLog method that captures the first argument that is passed to it + var capture string + oldInfo := infoLog + defer func() { infoLog = oldInfo }() + type WrapperType func() string + infoLog = func(format interface{}, args ...interface{}) { + // the code that we're testing passes a closure to the infoLog method, so we have to execute it to get the actual message back + if f, ok := format.(func() string); ok { + capture = WrapperType(f)() + } else { + t.Error("First parameter passed to Info is not a closure") + } + } + + // log something + emptyContext := context.Background() + var logMessage = "Some log message" + Infoc(emptyContext, logMessage) + + // check to see that the message is logged to the underlying log system, in this case our mock method + var deserialized LogMessage + json.Unmarshal([]byte(capture), &deserialized) + + assert.Empty(t, deserialized.Context) + assert.Equal(t, logMessage, deserialized.Message) + matched, err := regexp.MatchString(validPath, deserialized.File) + require.NoError(t, err) + assert.True(t, matched) +} + +// ensures that an infoLog message is passed through to the underlying logger as expected +func TestInfof(t *testing.T) { + // inject a "mocked" infoLog method that captures the first argument that is passed to it + var capture string + oldInfo := infoLog + defer func() { infoLog = oldInfo }() + type WrapperType func() string + infoLog = func(format interface{}, args ...interface{}) { + // the code that we're testing passes a closure to the infoLog method, so we have to execute it to get the actual message back + if f, ok := format.(func() string); ok { + capture = WrapperType(f)() + } else { + t.Error("First parameter passed to Info is not a closure") + } + } + + // log something + format := "Some %v message" + param := "log" + Infof(format, param) + + // check to see that the message is logged to the underlying log system, in this case our mock method + var deserialized LogMessage + json.Unmarshal([]byte(capture), &deserialized) + + assert.Empty(t, deserialized.Context) + assert.Equal(t, fmt.Sprintf(format, param), deserialized.Message) + matched, err := regexp.MatchString(validPath, deserialized.File) + require.NoError(t, err) + assert.True(t, matched) +} + +// ensures that an error message is passed through to the underlying logger as expected +func TestErrorc(t *testing.T) { + // inject a "mocked" err method that captures the first argument that is passed to it + var capture string + oldError := errorLog + defer func() { errorLog = oldError }() + type WrapperType func() string + errorLog = func(format interface{}, args ...interface{}) error { + // the code that we're testing passes a closure to the err method, so we have to execute it to get the actual message back + if f, ok := format.(func() string); ok { + capture = WrapperType(f)() + } else { + t.Error("First parameter passed to Error is not a closure") + } + + // the code under test doesn't care about this return value + return errors.New(capture) + } + + // log something + emptyContext := context.Background() + var logMessage = "Some log message" + Errorc(emptyContext, logMessage) + + // check to see that the message is logged to the underlying log system, in this case our mock method + var deserialized LogMessage + json.Unmarshal([]byte(capture), &deserialized) + + assert.Empty(t, deserialized.Context) + assert.Equal(t, logMessage, deserialized.Message) + matched, err := regexp.MatchString(validPath, deserialized.File) + require.NoError(t, err) + assert.True(t, matched) +} + +// ensures that an error message is passed through to the underlying logger as expected +func TestErrorf(t *testing.T) { + // inject a "mocked" err method that captures the first argument that is passed to it + var capture string + oldError := errorLog + defer func() { errorLog = oldError }() + type WrapperType func() string + errorLog = func(format interface{}, args ...interface{}) error { + // the code that we're testing passes a closure to the err method, so we have to execute it to get the actual message back + if f, ok := format.(func() string); ok { + capture = WrapperType(f)() + } else { + t.Error("First parameter passed to Error is not a closure") + } + + // the code under test doesn't care about this return value + return errors.New(capture) + } + + // log something + format := "Some %v message" + param := "log" + Errorf(format, param) + + // check to see that the message is logged to the underlying log system, in this case our mock method + var deserialized LogMessage + json.Unmarshal([]byte(capture), &deserialized) + + assert.Empty(t, deserialized.Context) + assert.Equal(t, fmt.Sprintf(format, param), deserialized.Message) + matched, err := regexp.MatchString(validPath, deserialized.File) + require.NoError(t, err) + assert.True(t, matched) +} |