Restored logger for mojang textures providers errors

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 {

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)
 	})

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)
+}

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:]...)
+				}
+			}
+		})
+	}
+}

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{}

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) {