From 280a55d553315d8eb825da245e4d62a940e06e2a Mon Sep 17 00:00:00 2001 From: ErickSkrauch Date: Thu, 2 Apr 2020 02:29:14 +0300 Subject: [PATCH] Restored logger for mojang textures providers errors --- api/mojang/mojang.go | 11 +- api/mojang/mojang_test.go | 14 +-- eventsubscribers/logger.go | 69 +++++++++++ eventsubscribers/logger_test.go | 151 ++++++++++++++++++++++++ eventsubscribers/stats_reporter_test.go | 2 +- tests/wd_mock.go | 41 ++++--- 6 files changed, 261 insertions(+), 27 deletions(-) create mode 100644 eventsubscribers/logger.go create mode 100644 eventsubscribers/logger_test.go diff --git a/api/mojang/mojang.go b/api/mojang/mojang.go index 14ec5d8..5e90566 100644 --- a/api/mojang/mojang.go +++ b/api/mojang/mojang.go @@ -3,6 +3,7 @@ package mojang import ( "bytes" "encoding/json" + "fmt" "io/ioutil" "net/http" "time" @@ -146,7 +147,7 @@ type EmptyResponse struct { } func (*EmptyResponse) Error() string { - return "Empty Response" + return "200: Empty Response" } func (*EmptyResponse) IsMojangError() bool { @@ -161,7 +162,7 @@ type BadRequestError struct { } func (e *BadRequestError) Error() string { - return e.Message + return fmt.Sprintf("400 %s: %s", e.ErrorType, e.Message) } func (*BadRequestError) IsMojangError() bool { @@ -174,7 +175,7 @@ type ForbiddenError struct { } func (*ForbiddenError) Error() string { - return "Forbidden" + return "403: Forbidden" } // When you exceed the set limit of requests, this error will be returned @@ -183,7 +184,7 @@ type TooManyRequestsError struct { } func (*TooManyRequestsError) Error() string { - return "Too Many Requests" + return "429: Too Many Requests" } func (*TooManyRequestsError) IsMojangError() bool { @@ -197,7 +198,7 @@ type ServerError struct { } func (e *ServerError) Error() string { - return "Server error" + return fmt.Sprintf("%d: %s", e.Status, "Server error") } func (*ServerError) IsMojangError() bool { diff --git a/api/mojang/mojang_test.go b/api/mojang/mojang_test.go index 2bffc81..44c7a96 100644 --- a/api/mojang/mojang_test.go +++ b/api/mojang/mojang_test.go @@ -98,7 +98,7 @@ func TestUsernamesToUuids(t *testing.T) { result, err := UsernamesToUuids([]string{""}) assert.Nil(result) assert.IsType(&BadRequestError{}, err) - assert.EqualError(err, "profileName can not be null or empty.") + assert.EqualError(err, "400 IllegalArgumentException: profileName can not be null or empty.") assert.Implements((*ResponseError)(nil), err) }) @@ -119,7 +119,7 @@ func TestUsernamesToUuids(t *testing.T) { result, err := UsernamesToUuids([]string{"Thinkofdeath", "maksimkurb"}) assert.Nil(result) assert.IsType(&ForbiddenError{}, err) - assert.EqualError(err, "Forbidden") + assert.EqualError(err, "403: Forbidden") assert.Implements((*ResponseError)(nil), err) }) @@ -143,7 +143,7 @@ func TestUsernamesToUuids(t *testing.T) { result, err := UsernamesToUuids([]string{"Thinkofdeath", "maksimkurb"}) assert.Nil(result) assert.IsType(&TooManyRequestsError{}, err) - assert.EqualError(err, "Too Many Requests") + assert.EqualError(err, "429: Too Many Requests") assert.Implements((*ResponseError)(nil), err) }) @@ -164,7 +164,7 @@ func TestUsernamesToUuids(t *testing.T) { result, err := UsernamesToUuids([]string{"Thinkofdeath", "maksimkurb"}) assert.Nil(result) assert.IsType(&ServerError{}, err) - assert.EqualError(err, "Server error") + assert.EqualError(err, "500: Server error") assert.Equal(500, err.(*ServerError).Status) assert.Implements((*ResponseError)(nil), err) }) @@ -258,7 +258,7 @@ func TestUuidToTextures(t *testing.T) { result, err := UuidToTextures("4566e69fc90748ee8d71d7ba5aa00d20", false) assert.Nil(result) assert.IsType(&EmptyResponse{}, err) - assert.EqualError(err, "Empty Response") + assert.EqualError(err, "200: Empty Response") assert.Implements((*ResponseError)(nil), err) }) @@ -282,7 +282,7 @@ func TestUuidToTextures(t *testing.T) { result, err := UuidToTextures("4566e69fc90748ee8d71d7ba5aa00d20", false) assert.Nil(result) assert.IsType(&TooManyRequestsError{}, err) - assert.EqualError(err, "Too Many Requests") + assert.EqualError(err, "429: Too Many Requests") assert.Implements((*ResponseError)(nil), err) }) @@ -303,7 +303,7 @@ func TestUuidToTextures(t *testing.T) { result, err := UuidToTextures("4566e69fc90748ee8d71d7ba5aa00d20", false) assert.Nil(result) assert.IsType(&ServerError{}, err) - assert.EqualError(err, "Server error") + assert.EqualError(err, "500: Server error") assert.Equal(500, err.(*ServerError).Status) assert.Implements((*ResponseError)(nil), err) }) diff --git a/eventsubscribers/logger.go b/eventsubscribers/logger.go new file mode 100644 index 0000000..2399ae7 --- /dev/null +++ b/eventsubscribers/logger.go @@ -0,0 +1,69 @@ +package eventsubscribers + +import ( + "net" + "net/url" + "syscall" + + "github.com/mono83/slf" + "github.com/mono83/slf/wd" + + "github.com/elyby/chrly/api/mojang" + "github.com/elyby/chrly/dispatcher" +) + +type Logger struct { + slf.Logger +} + +func (l *Logger) ConfigureWithDispatcher(d dispatcher.EventDispatcher) { + d.Subscribe("mojang_textures:usernames:after_call", l.createMojangTexturesErrorHandler("usernames")) + d.Subscribe("mojang_textures:textures:after_call", l.createMojangTexturesErrorHandler("textures")) +} + +func (l *Logger) createMojangTexturesErrorHandler(provider string) func(identity string, result interface{}, err error) { + providerParam := wd.NameParam(provider) + return func(identity string, result interface{}, err error) { + if err == nil { + return + } + + errParam := wd.ErrParam(err) + + l.Debug("Mojang "+provider+" provider resulted an error :err", errParam) + + switch err.(type) { + case *mojang.BadRequestError: + l.logMojangTexturesWarning(providerParam, errParam) + return + case *mojang.ForbiddenError: + l.logMojangTexturesWarning(providerParam, errParam) + return + case *mojang.TooManyRequestsError: + l.logMojangTexturesWarning(providerParam, errParam) + return + case net.Error: + if err.(net.Error).Timeout() { + return + } + + if _, ok := err.(*url.Error); ok { + return + } + + if opErr, ok := err.(*net.OpError); ok && (opErr.Op == "dial" || opErr.Op == "read") { + return + } + + if err == syscall.ECONNREFUSED { + return + } + } + + l.Error(":name: Unexpected Mojang response error: :err", providerParam, errParam) + } +} + +func (l *Logger) logMojangTexturesWarning(providerParam slf.Param, errParam slf.Param) { + l.Warning(":name: :err", providerParam, errParam) +} diff --git a/eventsubscribers/logger_test.go b/eventsubscribers/logger_test.go new file mode 100644 index 0000000..42062a9 --- /dev/null +++ b/eventsubscribers/logger_test.go @@ -0,0 +1,151 @@ +package eventsubscribers + +import ( + "net" + "net/url" + "syscall" + "testing" + + "github.com/mono83/slf/params" + "github.com/stretchr/testify/mock" + + "github.com/elyby/chrly/api/mojang" + "github.com/elyby/chrly/dispatcher" + "github.com/elyby/chrly/tests" +) + +type LoggerTestCase struct { + Events [][]interface{} + ExpectedCalls [][]interface{} +} + +var loggerTestCases = map[string]*LoggerTestCase{} + +type timeoutError struct{} + +func (*timeoutError) Error() string { return "timeout error" } +func (*timeoutError) Timeout() bool { return true } +func (*timeoutError) Temporary() bool { return false } + +func init() { + // mojang_textures providers errors + for _, providerName := range []string{"usernames", "textures"} { + pn := providerName // Store pointer to iteration value + loggerTestCases["should not log when no error occurred for "+pn+" provider"] = &LoggerTestCase{ + Events: [][]interface{}{ + {"mojang_textures:" + pn + ":after_call", pn, &mojang.ProfileInfo{}, nil}, + }, + ExpectedCalls: nil, + } + + loggerTestCases["should not log when some network errors occured for "+pn+" provider"] = &LoggerTestCase{ + Events: [][]interface{}{ + {"mojang_textures:" + pn + ":after_call", pn, nil, &timeoutError{}}, + {"mojang_textures:" + pn + ":after_call", pn, nil, &url.Error{Op: "GET", URL: "http://localhost"}}, + {"mojang_textures:" + pn + ":after_call", pn, nil, &net.OpError{Op: "read"}}, + {"mojang_textures:" + pn + ":after_call", pn, nil, &net.OpError{Op: "dial"}}, + {"mojang_textures:" + pn + ":after_call", pn, nil, syscall.ECONNREFUSED}, + }, + ExpectedCalls: [][]interface{}{ + {"Debug", "Mojang " + pn + " provider resulted an error :err", mock.AnythingOfType("params.Error")}, + }, + } + + loggerTestCases["should log expected mojang errors for "+pn+" provider"] = &LoggerTestCase{ + Events: [][]interface{}{ + {"mojang_textures:" + pn + ":after_call", pn, nil, &mojang.BadRequestError{ + ErrorType: "IllegalArgumentException", + Message: "profileName can not be null or empty.", + }}, + {"mojang_textures:" + pn + ":after_call", pn, nil, &mojang.ForbiddenError{}}, + {"mojang_textures:" + pn + ":after_call", pn, nil, &mojang.TooManyRequestsError{}}, + }, + ExpectedCalls: [][]interface{}{ + {"Debug", "Mojang " + pn + " provider resulted an error :err", mock.AnythingOfType("params.Error")}, + {"Warning", + ":name: :err", + mock.MatchedBy(func(strParam params.String) bool { + return strParam.Key == "name" && strParam.Value == pn + }), + mock.MatchedBy(func(errParam params.Error) bool { + if errParam.Key != "err" { + return false + } + + if _, ok := errParam.Value.(*mojang.BadRequestError); ok { + return true + } + + if _, ok := errParam.Value.(*mojang.ForbiddenError); ok { + return true + } + + if _, ok := errParam.Value.(*mojang.TooManyRequestsError); ok { + return true + } + + return false + }), + }, + }, + } + + loggerTestCases["should call error when unexpected error occurred for "+pn+" provider"] = &LoggerTestCase{ + Events: [][]interface{}{ + {"mojang_textures:" + pn + ":after_call", pn, nil, &mojang.ServerError{Status: 500}}, + }, + ExpectedCalls: [][]interface{}{ + {"Debug", "Mojang " + pn + " provider resulted an error :err", mock.AnythingOfType("params.Error")}, + {"Error", + ":name: Unexpected Mojang response error: :err", + mock.MatchedBy(func(strParam params.String) bool { + return strParam.Key == "name" && strParam.Value == pn + }), + mock.MatchedBy(func(errParam params.Error) bool { + if errParam.Key != "err" { + return false + } + + if _, ok := errParam.Value.(*mojang.ServerError); !ok { + return false + } + + return true + }), + }, + }, + } + } +} + +func TestLogger(t *testing.T) { + for name, c := range loggerTestCases { + t.Run(name, func(t *testing.T) { + wdMock := &tests.WdMock{} + if c.ExpectedCalls != nil { + for _, c := range c.ExpectedCalls { + topicName, _ := c[0].(string) + wdMock.On(topicName, c[1:]...) + } + } + + reporter := &Logger{ + Logger: wdMock, + } + + d := dispatcher.New() + reporter.ConfigureWithDispatcher(d) + for _, args := range c.Events { + eventName, _ := args[0].(string) + d.Emit(eventName, args[1:]...) + } + + if c.ExpectedCalls != nil { + for _, c := range c.ExpectedCalls { + topicName, _ := c[0].(string) + wdMock.AssertCalled(t, topicName, c[1:]...) + } + } + }) + } +} diff --git a/eventsubscribers/stats_reporter_test.go b/eventsubscribers/stats_reporter_test.go index 0bc8ecd..51b5b93 100644 --- a/eventsubscribers/stats_reporter_test.go +++ b/eventsubscribers/stats_reporter_test.go @@ -323,7 +323,7 @@ var statsReporterTestCases = []*StatsReporterTestCase{ }, } -func TestStatsReporter_handleEvents(t *testing.T) { +func TestStatsReporter(t *testing.T) { for _, c := range statsReporterTestCases { t.Run("handle events", func(t *testing.T) { wdMock := &tests.WdMock{} diff --git a/tests/wd_mock.go b/tests/wd_mock.go index 1d30a60..62d7bd1 100644 --- a/tests/wd_mock.go +++ b/tests/wd_mock.go @@ -8,36 +8,49 @@ import ( "github.com/stretchr/testify/mock" ) +func paramsSliceToInterfaceSlice(params []slf.Param) []interface{} { + result := make([]interface{}, len(params)) + for i, v := range params { + result[i], _ = v.(interface{}) + } + + return result +} + +func prepareLoggerArgs(message string, params []slf.Param) []interface{} { + return append([]interface{}{message}, paramsSliceToInterfaceSlice(params)...) +} + type WdMock struct { mock.Mock } -func (m *WdMock) Trace(message string, p ...slf.Param) { - m.Called(message) +func (m *WdMock) Trace(message string, params ...slf.Param) { + m.Called(prepareLoggerArgs(message, params)...) } -func (m *WdMock) Debug(message string, p ...slf.Param) { - m.Called(message) +func (m *WdMock) Debug(message string, params ...slf.Param) { + m.Called(prepareLoggerArgs(message, params)...) } -func (m *WdMock) Info(message string, p ...slf.Param) { - m.Called(message) +func (m *WdMock) Info(message string, params ...slf.Param) { + m.Called(prepareLoggerArgs(message, params)...) } -func (m *WdMock) Warning(message string, p ...slf.Param) { - m.Called(message) +func (m *WdMock) Warning(message string, params ...slf.Param) { + m.Called(prepareLoggerArgs(message, params)...) } -func (m *WdMock) Error(message string, p ...slf.Param) { - m.Called(message) +func (m *WdMock) Error(message string, params ...slf.Param) { + m.Called(prepareLoggerArgs(message, params)...) } -func (m *WdMock) Alert(message string, p ...slf.Param) { - m.Called(message) +func (m *WdMock) Alert(message string, params ...slf.Param) { + m.Called(prepareLoggerArgs(message, params)...) } -func (m *WdMock) Emergency(message string, p ...slf.Param) { - m.Called(message) +func (m *WdMock) Emergency(message string, params ...slf.Param) { + m.Called(prepareLoggerArgs(message, params)...) } func (m *WdMock) IncCounter(name string, value int64, p ...slf.Param) {