From b2ee10f72fb86c5b86af54deda92aa4266b1c778 Mon Sep 17 00:00:00 2001 From: ErickSkrauch Date: Wed, 29 Jan 2020 01:34:15 +0300 Subject: [PATCH 01/18] Completely rework the HTTP app layer structure. Replace a logger with an event dispatcher. Adjust tests to the new app architecture. --- cmd/serve.go | 10 ++-- cmd/worker.go | 11 ++-- http/http.go | 23 ++++++++ http/http_test.go | 9 +++ http/skinsystem.go | 112 ++++++++++++-------------------------- http/skinsystem_test.go | 107 ++++++++++++++++++++---------------- http/uuids_worker.go | 31 +---------- http/uuids_worker_test.go | 27 +++++---- 8 files changed, 156 insertions(+), 174 deletions(-) diff --git a/cmd/serve.go b/cmd/serve.go index 3732e33..5510627 100644 --- a/cmd/serve.go +++ b/cmd/serve.go @@ -74,20 +74,20 @@ var serveCmd = &cobra.Command{ } logger.Info("Mojang's textures queue is successfully initialized") - cfg := &http.Skinsystem{ - ListenSpec: fmt.Sprintf("%s:%d", viper.GetString("server.host"), viper.GetInt("server.port")), + address := fmt.Sprintf("%s:%d", viper.GetString("server.host"), viper.GetInt("server.port")) + handler := (&http.Skinsystem{ SkinsRepo: skinsRepo, CapesRepo: capesRepo, MojangTexturesProvider: mojangTexturesProvider, - Logger: logger, Auth: &auth.JwtAuth{Key: []byte(viper.GetString("chrly.secret"))}, TexturesExtraParamName: viper.GetString("textures.extra_param_name"), TexturesExtraParamValue: viper.GetString("textures.extra_param_value"), - } + }).CreateHandler() finishChan := make(chan bool) go func() { - if err := cfg.Run(); err != nil { + logger.Info(fmt.Sprintf("Starting the app, HTTP on: %s", address)) + if err := http.Serve(address, handler); err != nil { logger.Error(fmt.Sprintf("Error in main(): %v", err)) finishChan <- true } diff --git a/cmd/worker.go b/cmd/worker.go index 79ef7ed..e2ac655 100644 --- a/cmd/worker.go +++ b/cmd/worker.go @@ -28,15 +28,16 @@ var workerCmd = &cobra.Command{ return } - cfg := &http.UUIDsWorker{ - ListenSpec: fmt.Sprintf("%s:%d", viper.GetString("server.host"), viper.GetInt("server.port")), + address := fmt.Sprintf("%s:%d", viper.GetString("server.host"), viper.GetInt("server.port")) + handler := (&http.UUIDsWorker{ UUIDsProvider: uuidsProvider, - Logger: logger, - } + // TODO: create an emitter, restore logger + }).CreateHandler() finishChan := make(chan bool) go func() { - if err := cfg.Run(); err != nil { + logger.Info(fmt.Sprintf("Starting the worker, HTTP on: %s", address)) + if err := http.Serve(address, handler); err != nil { logger.Error(fmt.Sprintf("Error in main(): %v", err)) finishChan <- true } diff --git a/http/http.go b/http/http.go index aec1182..6a76daf 100644 --- a/http/http.go +++ b/http/http.go @@ -2,9 +2,32 @@ package http import ( "encoding/json" + "net" "net/http" + "time" ) +type Emitter interface { + Emit(name string, args ...interface{}) +} + +func Serve(address string, handler http.Handler) error { + listener, err := net.Listen("tcp", address) + if err != nil { + return err + } + + server := &http.Server{ + ReadTimeout: 5 * time.Second, + WriteTimeout: 5 * time.Second, + IdleTimeout: 60 * time.Second, + MaxHeaderBytes: 1 << 16, + Handler: handler, + } + + return server.Serve(listener) +} + func NotFound(response http.ResponseWriter, _ *http.Request) { data, _ := json.Marshal(map[string]string{ "status": "404", diff --git a/http/http_test.go b/http/http_test.go index 2b6d93d..376f1f6 100644 --- a/http/http_test.go +++ b/http/http_test.go @@ -6,8 +6,17 @@ import ( "testing" testify "github.com/stretchr/testify/assert" + "github.com/stretchr/testify/mock" ) +type emitterMock struct { + mock.Mock +} + +func (e *emitterMock) Emit(name string, args ...interface{}) { + e.Called((append([]interface{}{name}, args...))...) +} + func TestConfig_NotFound(t *testing.T) { assert := testify.New(t) diff --git a/http/skinsystem.go b/http/skinsystem.go index 86d4b04..0022941 100644 --- a/http/skinsystem.go +++ b/http/skinsystem.go @@ -5,15 +5,12 @@ import ( "errors" "fmt" "io" - "net" "net/http" "regexp" "strconv" "strings" - "time" "github.com/gorilla/mux" - "github.com/mono83/slf/wd" "github.com/thedevsaddam/govalidator" "github.com/elyby/chrly/api/mojang" @@ -21,7 +18,6 @@ import ( "github.com/elyby/chrly/model" ) -//noinspection GoSnakeCaseUsage const UUID_ANY = "^[0-9a-f]{8}-[0-9a-f]{4}-[0-9a-f]{4}-[0-9a-f]{4}-[0-9a-f]{12}$" var regexUuidAny = regexp.MustCompile(UUID_ANY) @@ -67,7 +63,7 @@ type SkinNotFoundError struct { } func (e SkinNotFoundError) Error() string { - return "Skin data not found." + return "skin data not found" } type CapeNotFoundError struct { @@ -75,7 +71,7 @@ type CapeNotFoundError struct { } func (e CapeNotFoundError) Error() string { - return "Cape file not found." + return "cape file not found" } type MojangTexturesProvider interface { @@ -87,33 +83,13 @@ type AuthChecker interface { } type Skinsystem struct { - ListenSpec string + Emitter TexturesExtraParamName string TexturesExtraParamValue string - - SkinsRepo SkinsRepository - CapesRepo CapesRepository - MojangTexturesProvider MojangTexturesProvider - Auth AuthChecker - Logger wd.Watchdog -} - -func (ctx *Skinsystem) Run() error { - ctx.Logger.Info(fmt.Sprintf("Starting the app, HTTP on: %s\n", ctx.ListenSpec)) - - listener, err := net.Listen("tcp", ctx.ListenSpec) - if err != nil { - return err - } - - server := &http.Server{ - ReadTimeout: 60 * time.Second, - WriteTimeout: 60 * time.Second, - MaxHeaderBytes: 1 << 16, - Handler: ctx.CreateHandler(), - } - - return server.Serve(listener) + SkinsRepo SkinsRepository + CapesRepo CapesRepository + MojangTexturesProvider MojangTexturesProvider + Auth AuthChecker } func (ctx *Skinsystem) CreateHandler() *mux.Router { @@ -129,9 +105,9 @@ func (ctx *Skinsystem) CreateHandler() *mux.Router { // API apiRouter := router.PathPrefix("/api").Subrouter() apiRouter.Use(ctx.AuthenticationMiddleware) - apiRouter.Handle("/skins", http.HandlerFunc(ctx.PostSkin)).Methods("POST") - apiRouter.Handle("/skins/id:{id:[0-9]+}", http.HandlerFunc(ctx.DeleteSkinByUserId)).Methods("DELETE") - apiRouter.Handle("/skins/{username}", http.HandlerFunc(ctx.DeleteSkinByUsername)).Methods("DELETE") + apiRouter.HandleFunc("/skins", ctx.PostSkin).Methods("POST") + apiRouter.HandleFunc("/skins/id:{id:[0-9]+}", ctx.DeleteSkinByUserId).Methods("DELETE") + apiRouter.HandleFunc("/skins/{username}", ctx.DeleteSkinByUsername).Methods("DELETE") // 404 router.NotFoundHandler = http.HandlerFunc(NotFound) @@ -139,10 +115,6 @@ func (ctx *Skinsystem) CreateHandler() *mux.Router { } func (ctx *Skinsystem) Skin(response http.ResponseWriter, request *http.Request) { - if mux.Vars(request)["converted"] == "" { - ctx.Logger.IncCounter("skins.request", 1) - } - username := parseUsername(mux.Vars(request)["username"]) rec, err := ctx.SkinsRepo.FindByUsername(username) if err == nil && rec.SkinId != 0 { @@ -173,7 +145,6 @@ func (ctx *Skinsystem) SkinGET(response http.ResponseWriter, request *http.Reque return } - ctx.Logger.IncCounter("skins.get_request", 1) mux.Vars(request)["username"] = username mux.Vars(request)["converted"] = "1" @@ -181,10 +152,6 @@ func (ctx *Skinsystem) SkinGET(response http.ResponseWriter, request *http.Reque } func (ctx *Skinsystem) Cape(response http.ResponseWriter, request *http.Request) { - if mux.Vars(request)["converted"] == "" { - ctx.Logger.IncCounter("capes.request", 1) - } - username := parseUsername(mux.Vars(request)["username"]) rec, err := ctx.CapesRepo.FindByUsername(username) if err == nil { @@ -216,7 +183,6 @@ func (ctx *Skinsystem) CapeGET(response http.ResponseWriter, request *http.Reque return } - ctx.Logger.IncCounter("capes.get_request", 1) mux.Vars(request)["username"] = username mux.Vars(request)["converted"] = "1" @@ -224,7 +190,6 @@ func (ctx *Skinsystem) CapeGET(response http.ResponseWriter, request *http.Reque } func (ctx *Skinsystem) Textures(response http.ResponseWriter, request *http.Request) { - ctx.Logger.IncCounter("textures.request", 1) username := parseUsername(mux.Vars(request)["username"]) var textures *mojang.TexturesResponse @@ -261,8 +226,8 @@ func (ctx *Skinsystem) Textures(response http.ResponseWriter, request *http.Requ texturesProp := mojangTextures.DecodeTextures() if texturesProp == nil { - response.WriteHeader(http.StatusInternalServerError) - ctx.Logger.Error("Unable to find textures property") + ctx.Emitter.Emit("skinsystem.error", errors.New("unable to find textures property")) + apiServerError(response) return } @@ -275,7 +240,6 @@ func (ctx *Skinsystem) Textures(response http.ResponseWriter, request *http.Requ } func (ctx *Skinsystem) SignedTextures(response http.ResponseWriter, request *http.Request) { - ctx.Logger.IncCounter("signed_textures.request", 1) username := parseUsername(mux.Vars(request)["username"]) var responseData *mojang.SignedTexturesResponse @@ -316,10 +280,8 @@ func (ctx *Skinsystem) SignedTextures(response http.ResponseWriter, request *htt } func (ctx *Skinsystem) PostSkin(resp http.ResponseWriter, req *http.Request) { - ctx.Logger.IncCounter("api.skins.post.request", 1) validationErrors := validatePostSkinRequest(req) if validationErrors != nil { - ctx.Logger.IncCounter("api.skins.post.validation_failed", 1) apiBadRequest(resp, validationErrors) return } @@ -329,7 +291,7 @@ func (ctx *Skinsystem) PostSkin(resp http.ResponseWriter, req *http.Request) { record, err := findIdentity(ctx.SkinsRepo, identityId, username) if err != nil { - ctx.Logger.Error("Error on requesting a skin from the repository: :err", wd.ErrParam(err)) + ctx.Emitter.Emit("skinsystem:error", fmt.Errorf("error on requesting a skin from the repository: %w", err)) apiServerError(resp) return } @@ -348,71 +310,67 @@ func (ctx *Skinsystem) PostSkin(resp http.ResponseWriter, req *http.Request) { err = ctx.SkinsRepo.Save(record) if err != nil { - ctx.Logger.Error("Unable to save record to the repository: :err", wd.ErrParam(err)) + ctx.Emitter.Emit("skinsystem:error", fmt.Errorf("unable to save record to the repository: %w", err)) apiServerError(resp) return } - ctx.Logger.IncCounter("api.skins.post.success", 1) resp.WriteHeader(http.StatusCreated) } func (ctx *Skinsystem) DeleteSkinByUserId(resp http.ResponseWriter, req *http.Request) { - ctx.Logger.IncCounter("api.skins.delete.request", 1) id, _ := strconv.Atoi(mux.Vars(req)["id"]) skin, err := ctx.SkinsRepo.FindByUserId(id) - if err != nil { - ctx.Logger.IncCounter("api.skins.delete.not_found", 1) - apiNotFound(resp, "Cannot find record for requested user id") - return - } - - ctx.deleteSkin(skin, resp) + ctx.deleteSkin(skin, err, resp) } func (ctx *Skinsystem) DeleteSkinByUsername(resp http.ResponseWriter, req *http.Request) { - ctx.Logger.IncCounter("api.skins.delete.request", 1) username := mux.Vars(req)["username"] skin, err := ctx.SkinsRepo.FindByUsername(username) - if err != nil { - ctx.Logger.IncCounter("api.skins.delete.not_found", 1) - apiNotFound(resp, "Cannot find record for requested username") - return - } - - ctx.deleteSkin(skin, resp) + ctx.deleteSkin(skin, err, resp) } func (ctx *Skinsystem) AuthenticationMiddleware(handler http.Handler) http.Handler { return http.HandlerFunc(func(resp http.ResponseWriter, req *http.Request) { - ctx.Logger.IncCounter("authentication.challenge", 1) + // TODO: decide on how I would cover this with logging + // ctx.Logger.IncCounter("authentication.challenge", 1) err := ctx.Auth.Check(req) if err != nil { if _, ok := err.(*auth.Unauthorized); ok { - ctx.Logger.IncCounter("authentication.failed", 1) + // ctx.Logger.IncCounter("authentication.failed", 1) apiForbidden(resp, err.Error()) } else { - ctx.Logger.Error("Unknown error on validating api request: :err", wd.ErrParam(err)) + // ctx.Logger.Error("Unknown error on validating api request: :err", wd.ErrParam(err)) apiServerError(resp) } return } - ctx.Logger.IncCounter("authentication.success", 1) + // ctx.Logger.IncCounter("authentication.success", 1) handler.ServeHTTP(resp, req) }) } -func (ctx *Skinsystem) deleteSkin(skin *model.Skin, resp http.ResponseWriter) { - err := ctx.SkinsRepo.RemoveByUserId(skin.UserId) +func (ctx *Skinsystem) deleteSkin(skin *model.Skin, err error, resp http.ResponseWriter) { if err != nil { - ctx.Logger.Error("Cannot delete skin by error: :err", wd.ErrParam(err)) + if _, ok := err.(*SkinNotFoundError); ok { + apiNotFound(resp, "Cannot find record for the requested identifier") + } else { + ctx.Emitter.Emit("skinsystem:error", fmt.Errorf("unable to find skin info from the repository: %w", err)) + apiServerError(resp) + } + + return + } + + err = ctx.SkinsRepo.RemoveByUserId(skin.UserId) + if err != nil { + ctx.Emitter.Emit("skinsystem:error", fmt.Errorf("cannot delete skin by error: %w", err)) apiServerError(resp) return } - ctx.Logger.IncCounter("api.skins.delete.success", 1) resp.WriteHeader(http.StatusNoContent) } diff --git a/http/skinsystem_test.go b/http/skinsystem_test.go index 463eeb2..78bc29c 100644 --- a/http/skinsystem_test.go +++ b/http/skinsystem_test.go @@ -3,8 +3,7 @@ package http import ( "bytes" "encoding/base64" - "github.com/elyby/chrly/auth" - testify "github.com/stretchr/testify/assert" + "errors" "image" "image/png" "io" @@ -16,12 +15,13 @@ import ( "testing" "time" + testify "github.com/stretchr/testify/assert" "github.com/stretchr/testify/mock" "github.com/stretchr/testify/suite" "github.com/elyby/chrly/api/mojang" + "github.com/elyby/chrly/auth" "github.com/elyby/chrly/model" - "github.com/elyby/chrly/tests" ) /*************** @@ -113,7 +113,7 @@ type skinsystemTestSuite struct { CapesRepository *capesRepositoryMock MojangTexturesProvider *mojangTexturesProviderMock Auth *authCheckerMock - Logger *tests.WdMock + Emitter *emitterMock } /******************** @@ -125,14 +125,14 @@ func (suite *skinsystemTestSuite) SetupTest() { suite.CapesRepository = &capesRepositoryMock{} suite.MojangTexturesProvider = &mojangTexturesProviderMock{} suite.Auth = &authCheckerMock{} - suite.Logger = &tests.WdMock{} + suite.Emitter = &emitterMock{} suite.App = &Skinsystem{ SkinsRepo: suite.SkinsRepository, CapesRepo: suite.CapesRepository, MojangTexturesProvider: suite.MojangTexturesProvider, Auth: suite.Auth, - Logger: suite.Logger, + Emitter: suite.Emitter, } } @@ -141,7 +141,7 @@ func (suite *skinsystemTestSuite) TearDownTest() { suite.CapesRepository.AssertExpectations(suite.T()) suite.MojangTexturesProvider.AssertExpectations(suite.T()) suite.Auth.AssertExpectations(suite.T()) - suite.Logger.AssertExpectations(suite.T()) + suite.Emitter.AssertExpectations(suite.T()) } func (suite *skinsystemTestSuite) RunSubTest(name string, subTest func()) { @@ -215,7 +215,6 @@ var skinsTestsCases = []*skinsystemTestCase{ func (suite *skinsystemTestSuite) TestSkin() { for _, testCase := range skinsTestsCases { suite.RunSubTest(testCase.Name, func() { - suite.Logger.On("IncCounter", "skins.request", int64(1)).Once() testCase.BeforeTest(suite) req := httptest.NewRequest("GET", "http://chrly/skins/mock_username", nil) @@ -228,7 +227,6 @@ func (suite *skinsystemTestSuite) TestSkin() { } suite.RunSubTest("Pass username with png extension", func() { - suite.Logger.On("IncCounter", "skins.request", int64(1)).Once() suite.SkinsRepository.On("FindByUsername", "mock_username").Return(createSkinModel("mock_username", false), nil) req := httptest.NewRequest("GET", "http://chrly/skins/mock_username.png", nil) @@ -245,7 +243,6 @@ func (suite *skinsystemTestSuite) TestSkin() { func (suite *skinsystemTestSuite) TestSkinGET() { for _, testCase := range skinsTestsCases { suite.RunSubTest(testCase.Name, func() { - suite.Logger.On("IncCounter", "skins.get_request", int64(1)).Once() testCase.BeforeTest(suite) req := httptest.NewRequest("GET", "http://chrly/skins?name=mock_username", nil) @@ -321,7 +318,6 @@ var capesTestsCases = []*skinsystemTestCase{ func (suite *skinsystemTestSuite) TestCape() { for _, testCase := range capesTestsCases { suite.RunSubTest(testCase.Name, func() { - suite.Logger.On("IncCounter", "capes.request", int64(1)).Once() testCase.BeforeTest(suite) req := httptest.NewRequest("GET", "http://chrly/cloaks/mock_username", nil) @@ -334,7 +330,6 @@ func (suite *skinsystemTestSuite) TestCape() { } suite.RunSubTest("Pass username with png extension", func() { - suite.Logger.On("IncCounter", "capes.request", int64(1)).Once() suite.CapesRepository.On("FindByUsername", "mock_username").Return(createCapeModel(), nil) req := httptest.NewRequest("GET", "http://chrly/cloaks/mock_username.png", nil) @@ -353,7 +348,6 @@ func (suite *skinsystemTestSuite) TestCape() { func (suite *skinsystemTestSuite) TestCapeGET() { for _, testCase := range capesTestsCases { suite.RunSubTest(testCase.Name, func() { - suite.Logger.On("IncCounter", "capes.get_request", int64(1)).Once() testCase.BeforeTest(suite) req := httptest.NewRequest("GET", "http://chrly/cloaks?name=mock_username", nil) @@ -492,7 +486,6 @@ var texturesTestsCases = []*skinsystemTestCase{ func (suite *skinsystemTestSuite) TestTextures() { for _, testCase := range texturesTestsCases { suite.RunSubTest(testCase.Name, func() { - suite.Logger.On("IncCounter", "textures.request", int64(1)).Once() testCase.BeforeTest(suite) req := httptest.NewRequest("GET", "http://chrly/textures/mock_username", nil) @@ -616,7 +609,6 @@ var signedTexturesTestsCases = []*signedTexturesTestCase{ func (suite *skinsystemTestSuite) TestSignedTextures() { for _, testCase := range signedTexturesTestsCases { suite.RunSubTest(testCase.Name, func() { - suite.Logger.On("IncCounter", "signed_textures.request", int64(1)).Once() testCase.BeforeTest(suite) var target string @@ -769,15 +761,62 @@ var postSkinTestsCases = []*postSkinTestCase{ suite.Empty(body) }, }, + { + Name: "Handle an error when loading the data from the repository", + Form: bytes.NewBufferString(url.Values{ + "identityId": {"1"}, + "username": {"mock_username"}, + "uuid": {"0f657aa8-bfbe-415d-b700-5750090d3af3"}, + "skinId": {"5"}, + "is1_8": {"1"}, + "isSlim": {"1"}, + "url": {"http://textures-server.com/skin.png"}, + }.Encode()), + BeforeTest: func(suite *skinsystemTestSuite) { + suite.SkinsRepository.On("FindByUserId", 1).Return(createSkinModel("mock_username", false), nil) + err := errors.New("mock error") + suite.SkinsRepository.On("Save", mock.Anything).Return(err) + suite.Emitter.On("Emit", "skinsystem:error", mock.MatchedBy(func(cErr error) bool { + return cErr.Error() == "unable to save record to the repository: mock error" && + errors.Is(cErr, err) + })).Once() + }, + AfterTest: func(suite *skinsystemTestSuite, response *http.Response) { + suite.Equal(500, response.StatusCode) + body, _ := ioutil.ReadAll(response.Body) + suite.Empty(body) + }, + }, + { + Name: "Handle an error when saving the data into the repository", + Form: bytes.NewBufferString(url.Values{ + "identityId": {"1"}, + "username": {"changed_username"}, + "uuid": {"0f657aa8-bfbe-415d-b700-5750090d3af3"}, + "skinId": {"5"}, + "is1_8": {"0"}, + "isSlim": {"0"}, + "url": {"http://example.com/skin.png"}, + }.Encode()), + BeforeTest: func(suite *skinsystemTestSuite) { + err := errors.New("mock error") + suite.SkinsRepository.On("FindByUserId", 1).Return(nil, err) + suite.Emitter.On("Emit", "skinsystem:error", mock.MatchedBy(func(cErr error) bool { + return cErr.Error() == "error on requesting a skin from the repository: mock error" && + errors.Is(cErr, err) + })).Once() + }, + AfterTest: func(suite *skinsystemTestSuite, response *http.Response) { + suite.Equal(500, response.StatusCode) + body, _ := ioutil.ReadAll(response.Body) + suite.Empty(body) + }, + }, } func (suite *skinsystemTestSuite) TestPostSkin() { for _, testCase := range postSkinTestsCases { suite.RunSubTest(testCase.Name, func() { - suite.Logger.On("IncCounter", "authentication.challenge", int64(1)).Once() - suite.Logger.On("IncCounter", "authentication.success", int64(1)).Once() - suite.Logger.On("IncCounter", "api.skins.post.request", int64(1)).Once() - suite.Logger.On("IncCounter", "api.skins.post.success", int64(1)).Once() suite.Auth.On("Check", mock.Anything).Return(nil) testCase.BeforeTest(suite) @@ -792,10 +831,6 @@ func (suite *skinsystemTestSuite) TestPostSkin() { } suite.RunSubTest("Get errors about required fields", func() { - suite.Logger.On("IncCounter", "authentication.challenge", int64(1)).Once() - suite.Logger.On("IncCounter", "authentication.success", int64(1)).Once() - suite.Logger.On("IncCounter", "api.skins.post.request", int64(1)).Once() - suite.Logger.On("IncCounter", "api.skins.post.validation_failed", int64(1)).Once() suite.Auth.On("Check", mock.Anything).Return(nil) req := httptest.NewRequest("POST", "http://chrly/api/skins", bytes.NewBufferString(url.Values{ @@ -848,8 +883,6 @@ func (suite *skinsystemTestSuite) TestPostSkin() { w := httptest.NewRecorder() suite.Auth.On("Check", mock.Anything).Return(&auth.Unauthorized{Reason: "Cannot parse passed JWT token"}) - suite.Logger.On("IncCounter", "authentication.challenge", int64(1)).Once() - suite.Logger.On("IncCounter", "authentication.failed", int64(1)).Once() suite.App.CreateHandler().ServeHTTP(w, req) @@ -863,10 +896,6 @@ func (suite *skinsystemTestSuite) TestPostSkin() { }) suite.RunSubTest("Upload textures with skin as file", func() { - suite.Logger.On("IncCounter", "authentication.challenge", int64(1)).Once() - suite.Logger.On("IncCounter", "authentication.success", int64(1)).Once() - suite.Logger.On("IncCounter", "api.skins.post.request", int64(1)).Once() - suite.Logger.On("IncCounter", "api.skins.post.validation_failed", int64(1)).Once() suite.Auth.On("Check", mock.Anything).Return(nil) inputBody := &bytes.Buffer{} @@ -914,10 +943,6 @@ func (suite *skinsystemTestSuite) TestDeleteByUserId() { suite.Auth.On("Check", mock.Anything).Return(nil) suite.SkinsRepository.On("FindByUserId", 1).Return(createSkinModel("mock_username", false), nil) suite.SkinsRepository.On("RemoveByUserId", 1).Once().Return(nil) - suite.Logger.On("IncCounter", "authentication.challenge", int64(1)).Once() - suite.Logger.On("IncCounter", "authentication.success", int64(1)).Once() - suite.Logger.On("IncCounter", "api.skins.delete.request", int64(1)).Once() - suite.Logger.On("IncCounter", "api.skins.delete.success", int64(1)).Once() req := httptest.NewRequest("DELETE", "http://chrly/api/skins/id:1", nil) w := httptest.NewRecorder() @@ -934,10 +959,6 @@ func (suite *skinsystemTestSuite) TestDeleteByUserId() { suite.RunSubTest("Try to remove not exists identity id", func() { suite.Auth.On("Check", mock.Anything).Return(nil) suite.SkinsRepository.On("FindByUserId", 1).Return(nil, &SkinNotFoundError{Who: "unknown"}) - suite.Logger.On("IncCounter", "authentication.challenge", int64(1)).Once() - suite.Logger.On("IncCounter", "authentication.success", int64(1)).Once() - suite.Logger.On("IncCounter", "api.skins.delete.request", int64(1)).Once() - suite.Logger.On("IncCounter", "api.skins.delete.not_found", int64(1)).Once() req := httptest.NewRequest("DELETE", "http://chrly/api/skins/id:1", nil) w := httptest.NewRecorder() @@ -949,7 +970,7 @@ func (suite *skinsystemTestSuite) TestDeleteByUserId() { suite.Equal(404, resp.StatusCode) body, _ := ioutil.ReadAll(resp.Body) suite.JSONEq(`[ - "Cannot find record for requested user id" + "Cannot find record for the requested identifier" ]`, string(body)) }) } @@ -963,10 +984,6 @@ func (suite *skinsystemTestSuite) TestDeleteByUsername() { suite.Auth.On("Check", mock.Anything).Return(nil) suite.SkinsRepository.On("FindByUsername", "mock_username").Return(createSkinModel("mock_username", false), nil) suite.SkinsRepository.On("RemoveByUserId", 1).Once().Return(nil) - suite.Logger.On("IncCounter", "authentication.challenge", int64(1)).Once() - suite.Logger.On("IncCounter", "authentication.success", int64(1)).Once() - suite.Logger.On("IncCounter", "api.skins.delete.request", int64(1)).Once() - suite.Logger.On("IncCounter", "api.skins.delete.success", int64(1)).Once() req := httptest.NewRequest("DELETE", "http://chrly/api/skins/mock_username", nil) w := httptest.NewRecorder() @@ -983,10 +1000,6 @@ func (suite *skinsystemTestSuite) TestDeleteByUsername() { suite.RunSubTest("Try to remove not exists identity username", func() { suite.Auth.On("Check", mock.Anything).Return(nil) suite.SkinsRepository.On("FindByUsername", "mock_username").Return(nil, &SkinNotFoundError{Who: "mock_username"}) - suite.Logger.On("IncCounter", "authentication.challenge", int64(1)).Once() - suite.Logger.On("IncCounter", "authentication.success", int64(1)).Once() - suite.Logger.On("IncCounter", "api.skins.delete.request", int64(1)).Once() - suite.Logger.On("IncCounter", "api.skins.delete.not_found", int64(1)).Once() req := httptest.NewRequest("DELETE", "http://chrly/api/skins/mock_username", nil) w := httptest.NewRecorder() @@ -998,7 +1011,7 @@ func (suite *skinsystemTestSuite) TestDeleteByUsername() { suite.Equal(404, resp.StatusCode) body, _ := ioutil.ReadAll(resp.Body) suite.JSONEq(`[ - "Cannot find record for requested username" + "Cannot find record for the requested identifier" ]`, string(body)) }) } diff --git a/http/uuids_worker.go b/http/uuids_worker.go index f983a5e..fd4aa16 100644 --- a/http/uuids_worker.go +++ b/http/uuids_worker.go @@ -2,13 +2,9 @@ package http import ( "encoding/json" - "fmt" - "net" "net/http" - "time" "github.com/gorilla/mux" - "github.com/mono83/slf/wd" "github.com/elyby/chrly/api/mojang" "github.com/elyby/chrly/mojangtextures" @@ -19,31 +15,11 @@ type UuidsProvider interface { } type UUIDsWorker struct { - ListenSpec string - + Emitter UUIDsProvider mojangtextures.UUIDsProvider - Logger wd.Watchdog } -func (ctx *UUIDsWorker) Run() error { - ctx.Logger.Info(fmt.Sprintf("Starting the worker, HTTP on: %s\n", ctx.ListenSpec)) - - listener, err := net.Listen("tcp", ctx.ListenSpec) - if err != nil { - return err - } - - server := &http.Server{ - ReadTimeout: 60 * time.Second, - WriteTimeout: 60 * time.Second, // TODO: should I adjust this values? - MaxHeaderBytes: 1 << 16, - Handler: ctx.CreateHandler(), - } - - return server.Serve(listener) -} - -func (ctx *UUIDsWorker) CreateHandler() http.Handler { +func (ctx *UUIDsWorker) CreateHandler() *mux.Router { router := mux.NewRouter().StrictSlash(true) router.NotFoundHandler = http.HandlerFunc(NotFound) @@ -56,13 +32,12 @@ func (ctx *UUIDsWorker) GetUUID(response http.ResponseWriter, request *http.Requ username := parseUsername(mux.Vars(request)["username"]) profile, err := ctx.UUIDsProvider.GetUuid(username) if err != nil { + ctx.Emitter.Emit("uuids_provider:error", err) // TODO: do I need emitter here? if _, ok := err.(*mojang.TooManyRequestsError); ok { - ctx.Logger.Warning("Got 429 Too Many Requests") response.WriteHeader(http.StatusTooManyRequests) return } - ctx.Logger.Warning("Got non success response: :err", wd.ErrParam(err)) response.Header().Set("Content-Type", "application/json") response.WriteHeader(http.StatusInternalServerError) result, _ := json.Marshal(map[string]interface{}{ diff --git a/http/uuids_worker_test.go b/http/uuids_worker_test.go index ea0e64e..0271dd8 100644 --- a/http/uuids_worker_test.go +++ b/http/uuids_worker_test.go @@ -2,14 +2,15 @@ package http import ( "errors" - "github.com/elyby/chrly/api/mojang" - "github.com/elyby/chrly/tests" - "github.com/stretchr/testify/mock" - "github.com/stretchr/testify/suite" "io/ioutil" "net/http" "net/http/httptest" "testing" + + "github.com/stretchr/testify/mock" + "github.com/stretchr/testify/suite" + + "github.com/elyby/chrly/api/mojang" ) /*************** @@ -36,7 +37,7 @@ type uuidsWorkerTestSuite struct { App *UUIDsWorker UuidsProvider *uuidsProviderMock - Logger *tests.WdMock + Emitter *emitterMock } /******************** @@ -45,17 +46,17 @@ type uuidsWorkerTestSuite struct { func (suite *uuidsWorkerTestSuite) SetupTest() { suite.UuidsProvider = &uuidsProviderMock{} - suite.Logger = &tests.WdMock{} + suite.Emitter = &emitterMock{} suite.App = &UUIDsWorker{ UUIDsProvider: suite.UuidsProvider, - Logger: suite.Logger, + Emitter: suite.Emitter, } } func (suite *uuidsWorkerTestSuite) TearDownTest() { suite.UuidsProvider.AssertExpectations(suite.T()) - suite.Logger.AssertExpectations(suite.T()) + suite.Emitter.AssertExpectations(suite.T()) } func (suite *uuidsWorkerTestSuite) RunSubTest(name string, subTest func()) { @@ -115,8 +116,9 @@ var getUuidTestsCases = []*uuidsWorkerTestCase{ { Name: "Receive error from UUIDs provider", BeforeTest: func(suite *uuidsWorkerTestSuite) { - suite.UuidsProvider.On("GetUuid", "mock_username").Return(nil, errors.New("this is an error")) - suite.Logger.On("Warning", "Got non success response: :err", mock.Anything).Times(1) + err := errors.New("this is an error") + suite.UuidsProvider.On("GetUuid", "mock_username").Return(nil, err) + suite.Emitter.On("Emit", "uuids_provider:error", err).Times(1) }, AfterTest: func(suite *uuidsWorkerTestSuite, response *http.Response) { suite.Equal(500, response.StatusCode) @@ -130,8 +132,9 @@ var getUuidTestsCases = []*uuidsWorkerTestCase{ { Name: "Receive Too Many Requests from UUIDs provider", BeforeTest: func(suite *uuidsWorkerTestSuite) { - suite.UuidsProvider.On("GetUuid", "mock_username").Return(nil, &mojang.TooManyRequestsError{}) - suite.Logger.On("Warning", "Got 429 Too Many Requests").Times(1) + err := &mojang.TooManyRequestsError{} + suite.UuidsProvider.On("GetUuid", "mock_username").Return(nil, err) + suite.Emitter.On("Emit", "uuids_provider:error", err).Times(1) }, AfterTest: func(suite *uuidsWorkerTestSuite, response *http.Response) { suite.Equal(429, response.StatusCode) From 2abe2db46936945a4e5cf21a1dda701906d38278 Mon Sep 17 00:00:00 2001 From: ErickSkrauch Date: Sat, 8 Feb 2020 13:28:10 +0300 Subject: [PATCH 02/18] Integrate event dispatcher into mojangtextures package --- bootstrap/bootstrap.go | 9 +- cmd/serve.go | 6 +- cmd/worker.go | 2 +- http/skinsystem.go | 10 +- http/uuids_worker.go | 2 +- mojangtextures/batch_uuids_provider.go | 22 +-- mojangtextures/batch_uuids_provider_test.go | 58 +++--- .../mojang_api_textures_provider.go | 12 +- .../mojang_api_textures_provider_test.go | 32 ++- mojangtextures/mojang_textures.go | 86 ++------ mojangtextures/mojang_textures_test.go | 187 ++++++------------ mojangtextures/remote_api_uuids_provider.go | 16 +- .../remote_api_uuids_provider_test.go | 60 ++++-- 13 files changed, 207 insertions(+), 295 deletions(-) diff --git a/bootstrap/bootstrap.go b/bootstrap/bootstrap.go index 4455e17..39a4b51 100644 --- a/bootstrap/bootstrap.go +++ b/bootstrap/bootstrap.go @@ -1,6 +1,7 @@ package bootstrap import ( + "github.com/elyby/chrly/http" "net/url" "os" "time" @@ -69,7 +70,7 @@ func init() { viper.SetDefault("queue.batch_size", 10) } -func CreateMojangUUIDsProvider(logger wd.Watchdog) (mojangtextures.UUIDsProvider, error) { +func CreateMojangUUIDsProvider(emitter http.Emitter) (mojangtextures.UUIDsProvider, error) { var uuidsProvider mojangtextures.UUIDsProvider preferredUuidsProvider := viper.GetString("mojang_textures.uuids_provider.driver") if preferredUuidsProvider == "remote" { @@ -79,14 +80,14 @@ func CreateMojangUUIDsProvider(logger wd.Watchdog) (mojangtextures.UUIDsProvider } uuidsProvider = &mojangtextures.RemoteApiUuidsProvider{ - Url: *remoteUrl, - Logger: logger, + Emitter: emitter, + Url: *remoteUrl, } } else { uuidsProvider = &mojangtextures.BatchUuidsProvider{ + Emitter: emitter, IterationDelay: viper.GetDuration("queue.loop_delay"), IterationSize: viper.GetInt("queue.batch_size"), - Logger: logger, } } diff --git a/cmd/serve.go b/cmd/serve.go index 5510627..010b8a2 100644 --- a/cmd/serve.go +++ b/cmd/serve.go @@ -53,7 +53,7 @@ var serveCmd = &cobra.Command{ return } - uuidsProvider, err := bootstrap.CreateMojangUUIDsProvider(logger) + uuidsProvider, err := bootstrap.CreateMojangUUIDsProvider(nil) if err != nil { logger.Emergency("Unable to parse remote url :err", wd.ErrParam(err)) return @@ -62,10 +62,10 @@ var serveCmd = &cobra.Command{ texturesStorage := mojangtextures.NewInMemoryTexturesStorage() texturesStorage.Start() mojangTexturesProvider := &mojangtextures.Provider{ - Logger: logger, + // TODO: configure emitter UUIDsProvider: uuidsProvider, TexturesProvider: &mojangtextures.MojangApiTexturesProvider{ - Logger: logger, + // TODO: configure emitter }, Storage: &mojangtextures.SeparatedStorage{ UuidsStorage: mojangUuidsRepository, diff --git a/cmd/worker.go b/cmd/worker.go index e2ac655..8f3f22a 100644 --- a/cmd/worker.go +++ b/cmd/worker.go @@ -31,7 +31,7 @@ var workerCmd = &cobra.Command{ address := fmt.Sprintf("%s:%d", viper.GetString("server.host"), viper.GetInt("server.port")) handler := (&http.UUIDsWorker{ UUIDsProvider: uuidsProvider, - // TODO: create an emitter, restore logger + // TODO: configure emitter }).CreateHandler() finishChan := make(chan bool) diff --git a/http/skinsystem.go b/http/skinsystem.go index 0022941..f608276 100644 --- a/http/skinsystem.go +++ b/http/skinsystem.go @@ -226,7 +226,7 @@ func (ctx *Skinsystem) Textures(response http.ResponseWriter, request *http.Requ texturesProp := mojangTextures.DecodeTextures() if texturesProp == nil { - ctx.Emitter.Emit("skinsystem.error", errors.New("unable to find textures property")) + ctx.Emit("skinsystem.error", errors.New("unable to find textures property")) apiServerError(response) return } @@ -291,7 +291,7 @@ func (ctx *Skinsystem) PostSkin(resp http.ResponseWriter, req *http.Request) { record, err := findIdentity(ctx.SkinsRepo, identityId, username) if err != nil { - ctx.Emitter.Emit("skinsystem:error", fmt.Errorf("error on requesting a skin from the repository: %w", err)) + ctx.Emit("skinsystem:error", fmt.Errorf("error on requesting a skin from the repository: %w", err)) apiServerError(resp) return } @@ -310,7 +310,7 @@ func (ctx *Skinsystem) PostSkin(resp http.ResponseWriter, req *http.Request) { err = ctx.SkinsRepo.Save(record) if err != nil { - ctx.Emitter.Emit("skinsystem:error", fmt.Errorf("unable to save record to the repository: %w", err)) + ctx.Emit("skinsystem:error", fmt.Errorf("unable to save record to the repository: %w", err)) apiServerError(resp) return } @@ -357,7 +357,7 @@ func (ctx *Skinsystem) deleteSkin(skin *model.Skin, err error, resp http.Respons if _, ok := err.(*SkinNotFoundError); ok { apiNotFound(resp, "Cannot find record for the requested identifier") } else { - ctx.Emitter.Emit("skinsystem:error", fmt.Errorf("unable to find skin info from the repository: %w", err)) + ctx.Emit("skinsystem:error", fmt.Errorf("unable to find skin info from the repository: %w", err)) apiServerError(resp) } @@ -366,7 +366,7 @@ func (ctx *Skinsystem) deleteSkin(skin *model.Skin, err error, resp http.Respons err = ctx.SkinsRepo.RemoveByUserId(skin.UserId) if err != nil { - ctx.Emitter.Emit("skinsystem:error", fmt.Errorf("cannot delete skin by error: %w", err)) + ctx.Emit("skinsystem:error", fmt.Errorf("cannot delete skin by error: %w", err)) apiServerError(resp) return } diff --git a/http/uuids_worker.go b/http/uuids_worker.go index fd4aa16..2296552 100644 --- a/http/uuids_worker.go +++ b/http/uuids_worker.go @@ -32,7 +32,7 @@ func (ctx *UUIDsWorker) GetUUID(response http.ResponseWriter, request *http.Requ username := parseUsername(mux.Vars(request)["username"]) profile, err := ctx.UUIDsProvider.GetUuid(username) if err != nil { - ctx.Emitter.Emit("uuids_provider:error", err) // TODO: do I need emitter here? + ctx.Emit("uuids_provider:error", err) // TODO: do I need emitter here? if _, ok := err.(*mojang.TooManyRequestsError); ok { response.WriteHeader(http.StatusTooManyRequests) return diff --git a/mojangtextures/batch_uuids_provider.go b/mojangtextures/batch_uuids_provider.go index b0b1826..c9cf612 100644 --- a/mojangtextures/batch_uuids_provider.go +++ b/mojangtextures/batch_uuids_provider.go @@ -5,8 +5,6 @@ import ( "sync" "time" - "github.com/mono83/slf/wd" - "github.com/elyby/chrly/api/mojang" ) @@ -68,9 +66,10 @@ var forever = func() bool { } type BatchUuidsProvider struct { + Emitter + IterationDelay time.Duration IterationSize int - Logger wd.Watchdog onFirstCall sync.Once queue jobsQueue @@ -84,7 +83,7 @@ func (ctx *BatchUuidsProvider) GetUuid(username string) (*mojang.ProfileInfo, er resultChan := make(chan *jobResult) ctx.queue.Enqueue(&jobItem{username, resultChan}) - ctx.Logger.IncCounter("mojang_textures.usernames.queued", 1) + ctx.Emit("mojang_textures:batch_uuids_provider:queued", username) result := <-resultChan @@ -95,10 +94,9 @@ func (ctx *BatchUuidsProvider) startQueue() { go func() { time.Sleep(ctx.IterationDelay) for forever() { - start := time.Now() + ctx.Emit("mojang_textures:batch_uuids_provider:before_round") ctx.queueRound() - elapsed := time.Since(start) - ctx.Logger.RecordTimer("mojang_textures.usernames.round_time", elapsed) + ctx.Emit("mojang_textures:batch_uuids_provider:after_round") time.Sleep(ctx.IterationDelay) } }() @@ -107,17 +105,17 @@ func (ctx *BatchUuidsProvider) startQueue() { func (ctx *BatchUuidsProvider) queueRound() { queueSize := ctx.queue.Size() jobs := ctx.queue.Dequeue(ctx.IterationSize) - ctx.Logger.UpdateGauge("mojang_textures.usernames.queue_size", int64(queueSize-len(jobs))) - ctx.Logger.UpdateGauge("mojang_textures.usernames.iteration_size", int64(len(jobs))) - if len(jobs) == 0 { - return - } var usernames []string for _, job := range jobs { usernames = append(usernames, job.username) } + ctx.Emit("mojang_textures:batch_uuids_provider:round", usernames, queueSize - len(jobs)) + if len(usernames) == 0 { + return + } + profiles, err := usernamesToUuids(usernames) for _, job := range jobs { go func(job *jobItem) { diff --git a/mojangtextures/batch_uuids_provider_test.go b/mojangtextures/batch_uuids_provider_test.go index f3f9f02..441374c 100644 --- a/mojangtextures/batch_uuids_provider_test.go +++ b/mojangtextures/batch_uuids_provider_test.go @@ -11,7 +11,6 @@ import ( "github.com/stretchr/testify/suite" "github.com/elyby/chrly/api/mojang" - mocks "github.com/elyby/chrly/tests" ) func TestJobsQueue(t *testing.T) { @@ -85,7 +84,7 @@ type batchUuidsProviderTestSuite struct { Provider *BatchUuidsProvider GetUuidAsync func(username string) chan *batchUuidsProviderGetUuidResult - Logger *mocks.WdMock + Emitter *mockEmitter MojangApi *mojangUsernamesToUuidsRequestMock Iterate func() @@ -94,10 +93,10 @@ type batchUuidsProviderTestSuite struct { } func (suite *batchUuidsProviderTestSuite) SetupTest() { - suite.Logger = &mocks.WdMock{} + suite.Emitter = &mockEmitter{} suite.Provider = &BatchUuidsProvider{ - Logger: suite.Logger, + Emitter: suite.Emitter, IterationDelay: 0, IterationSize: 10, } @@ -120,7 +119,10 @@ func (suite *batchUuidsProviderTestSuite) SetupTest() { // This dirty hack ensures, that the username will be queued before we return control to the caller. // It's needed to keep expected calls order and prevent cases when iteration happens before all usernames // will be queued. - suite.Logger.On("IncCounter", "mojang_textures.usernames.queued", int64(1)).Once().Run(func(args mock.Arguments) { + suite.Emitter.On("Emit", + "mojang_textures:batch_uuids_provider:queued", + username, + ).Once().Run(func(args mock.Arguments) { s <- true }) @@ -144,8 +146,8 @@ func (suite *batchUuidsProviderTestSuite) SetupTest() { func (suite *batchUuidsProviderTestSuite) TearDownTest() { suite.done() + suite.Emitter.AssertExpectations(suite.T()) suite.MojangApi.AssertExpectations(suite.T()) - suite.Logger.AssertExpectations(suite.T()) } func TestBatchUuidsProvider(t *testing.T) { @@ -155,9 +157,9 @@ func TestBatchUuidsProvider(t *testing.T) { func (suite *batchUuidsProviderTestSuite) TestGetUuidForOneUsername() { expectedResult := &mojang.ProfileInfo{Id: "aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa", Name: "username"} - suite.Logger.On("UpdateGauge", "mojang_textures.usernames.iteration_size", int64(1)).Once() - suite.Logger.On("UpdateGauge", "mojang_textures.usernames.queue_size", int64(0)).Once() - suite.Logger.On("RecordTimer", "mojang_textures.usernames.round_time", mock.Anything).Once() + suite.Emitter.On("Emit", "mojang_textures:batch_uuids_provider:before_round").Once() + suite.Emitter.On("Emit", "mojang_textures:batch_uuids_provider:round", []string{"username"}, 0).Once() + suite.Emitter.On("Emit", "mojang_textures:batch_uuids_provider:after_round").Once() suite.MojangApi.On("UsernamesToUuids", []string{"username"}).Once().Return([]*mojang.ProfileInfo{expectedResult}, nil) @@ -174,9 +176,9 @@ func (suite *batchUuidsProviderTestSuite) TestGetUuidForTwoUsernames() { expectedResult1 := &mojang.ProfileInfo{Id: "aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa", Name: "username1"} expectedResult2 := &mojang.ProfileInfo{Id: "bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb", Name: "username2"} - suite.Logger.On("UpdateGauge", "mojang_textures.usernames.iteration_size", int64(2)).Once() - suite.Logger.On("UpdateGauge", "mojang_textures.usernames.queue_size", int64(0)).Once() - suite.Logger.On("RecordTimer", "mojang_textures.usernames.round_time", mock.Anything).Once() + suite.Emitter.On("Emit", "mojang_textures:batch_uuids_provider:before_round").Once() + suite.Emitter.On("Emit", "mojang_textures:batch_uuids_provider:round", []string{"username1", "username2"}, 0).Once() + suite.Emitter.On("Emit", "mojang_textures:batch_uuids_provider:after_round").Once() suite.MojangApi.On("UsernamesToUuids", []string{"username1", "username2"}).Once().Return([]*mojang.ProfileInfo{ expectedResult1, @@ -203,18 +205,13 @@ func (suite *batchUuidsProviderTestSuite) TestGetUuidForMoreThan10Usernames() { usernames[i] = randStr(8) } - suite.Logger.On("UpdateGauge", "mojang_textures.usernames.iteration_size", int64(10)).Once() - suite.Logger.On("UpdateGauge", "mojang_textures.usernames.iteration_size", int64(2)).Once() - suite.Logger.On("UpdateGauge", "mojang_textures.usernames.queue_size", int64(2)).Once() - suite.Logger.On("UpdateGauge", "mojang_textures.usernames.queue_size", int64(0)).Once() - suite.Logger.On("RecordTimer", "mojang_textures.usernames.round_time", mock.Anything).Twice() + suite.Emitter.On("Emit", "mojang_textures:batch_uuids_provider:before_round").Twice() + suite.Emitter.On("Emit", "mojang_textures:batch_uuids_provider:round", usernames[0:10], 2).Once() + suite.Emitter.On("Emit", "mojang_textures:batch_uuids_provider:round", usernames[10:12], 0).Once() + suite.Emitter.On("Emit", "mojang_textures:batch_uuids_provider:after_round").Twice() - suite.MojangApi.On("UsernamesToUuids", mock.MatchedBy(func(usernames []string) bool { - return len(usernames) == 10 - })).Once().Return([]*mojang.ProfileInfo{}, nil) - suite.MojangApi.On("UsernamesToUuids", mock.MatchedBy(func(usernames []string) bool { - return len(usernames) == 2 - })).Once().Return([]*mojang.ProfileInfo{}, nil) + suite.MojangApi.On("UsernamesToUuids", usernames[0:10]).Once().Return([]*mojang.ProfileInfo{}, nil) + suite.MojangApi.On("UsernamesToUuids", usernames[10:12]).Once().Return([]*mojang.ProfileInfo{}, nil) channels := make([]chan *batchUuidsProviderGetUuidResult, len(usernames)) for i, username := range usernames { @@ -230,10 +227,11 @@ func (suite *batchUuidsProviderTestSuite) TestGetUuidForMoreThan10Usernames() { } func (suite *batchUuidsProviderTestSuite) TestDoNothingWhenNoTasks() { - suite.Logger.On("UpdateGauge", "mojang_textures.usernames.iteration_size", int64(1)).Once() - suite.Logger.On("UpdateGauge", "mojang_textures.usernames.iteration_size", int64(0)).Twice() - suite.Logger.On("UpdateGauge", "mojang_textures.usernames.queue_size", int64(0)).Times(3) - suite.Logger.On("RecordTimer", "mojang_textures.usernames.round_time", mock.Anything) + suite.Emitter.On("Emit", "mojang_textures:batch_uuids_provider:before_round").Times(3) + suite.Emitter.On("Emit", "mojang_textures:batch_uuids_provider:round", []string{"username"}, 0).Once() + var nilStringSlice []string + suite.Emitter.On("Emit", "mojang_textures:batch_uuids_provider:round", nilStringSlice, 0).Twice() + suite.Emitter.On("Emit", "mojang_textures:batch_uuids_provider:after_round").Times(3) suite.MojangApi.On("UsernamesToUuids", []string{"username"}).Once().Return([]*mojang.ProfileInfo{}, nil) @@ -254,9 +252,9 @@ func (suite *batchUuidsProviderTestSuite) TestDoNothingWhenNoTasks() { func (suite *batchUuidsProviderTestSuite) TestGetUuidForTwoUsernamesWithAnError() { expectedError := &mojang.TooManyRequestsError{} - suite.Logger.On("UpdateGauge", "mojang_textures.usernames.iteration_size", int64(2)).Once() - suite.Logger.On("UpdateGauge", "mojang_textures.usernames.queue_size", int64(0)).Once() - suite.Logger.On("RecordTimer", "mojang_textures.usernames.round_time", mock.Anything).Once() + suite.Emitter.On("Emit", "mojang_textures:batch_uuids_provider:before_round").Once() + suite.Emitter.On("Emit", "mojang_textures:batch_uuids_provider:round", []string{"username1", "username2"}, 0).Once() + suite.Emitter.On("Emit", "mojang_textures:batch_uuids_provider:after_round").Once() suite.MojangApi.On("UsernamesToUuids", []string{"username1", "username2"}).Once().Return(nil, expectedError) diff --git a/mojangtextures/mojang_api_textures_provider.go b/mojangtextures/mojang_api_textures_provider.go index 716f316..543ffda 100644 --- a/mojangtextures/mojang_api_textures_provider.go +++ b/mojangtextures/mojang_api_textures_provider.go @@ -1,25 +1,19 @@ package mojangtextures import ( - "time" - - "github.com/mono83/slf/wd" - "github.com/elyby/chrly/api/mojang" ) var uuidToTextures = mojang.UuidToTextures type MojangApiTexturesProvider struct { - Logger wd.Watchdog + Emitter } func (ctx *MojangApiTexturesProvider) GetTextures(uuid string) (*mojang.SignedTexturesResponse, error) { - ctx.Logger.IncCounter("mojang_textures.textures.request", 1) - - start := time.Now() + ctx.Emit("mojang_textures:mojang_api_textures_provider:before_request", uuid) result, err := uuidToTextures(uuid, true) - ctx.Logger.RecordTimer("mojang_textures.textures.request_time", time.Since(start)) + ctx.Emit("mojang_textures:mojang_api_textures_provider:after_request", result, err) return result, err } diff --git a/mojangtextures/mojang_api_textures_provider_test.go b/mojangtextures/mojang_api_textures_provider_test.go index ed2a349..e837a48 100644 --- a/mojangtextures/mojang_api_textures_provider_test.go +++ b/mojangtextures/mojang_api_textures_provider_test.go @@ -7,7 +7,6 @@ import ( "github.com/stretchr/testify/suite" "github.com/elyby/chrly/api/mojang" - mocks "github.com/elyby/chrly/tests" ) type mojangUuidToTexturesRequestMock struct { @@ -28,16 +27,16 @@ type mojangApiTexturesProviderTestSuite struct { suite.Suite Provider *MojangApiTexturesProvider - Logger *mocks.WdMock + Emitter *mockEmitter MojangApi *mojangUuidToTexturesRequestMock } func (suite *mojangApiTexturesProviderTestSuite) SetupTest() { - suite.Logger = &mocks.WdMock{} + suite.Emitter = &mockEmitter{} suite.MojangApi = &mojangUuidToTexturesRequestMock{} suite.Provider = &MojangApiTexturesProvider{ - Logger: suite.Logger, + Emitter: suite.Emitter, } uuidToTextures = suite.MojangApi.UuidToTextures @@ -45,7 +44,7 @@ func (suite *mojangApiTexturesProviderTestSuite) SetupTest() { func (suite *mojangApiTexturesProviderTestSuite) TearDownTest() { suite.MojangApi.AssertExpectations(suite.T()) - suite.Logger.AssertExpectations(suite.T()) + suite.Emitter.AssertExpectations(suite.T()) } func TestMojangApiTexturesProvider(t *testing.T) { @@ -59,8 +58,15 @@ func (suite *mojangApiTexturesProviderTestSuite) TestGetTextures() { } suite.MojangApi.On("UuidToTextures", "aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa", true).Once().Return(expectedResult, nil) - suite.Logger.On("IncCounter", "mojang_textures.textures.request", int64(1)).Once() - suite.Logger.On("RecordTimer", "mojang_textures.textures.request_time", mock.Anything).Once() + suite.Emitter.On("Emit", + "mojang_textures:mojang_api_textures_provider:before_request", + "aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa", + ).Once() + suite.Emitter.On("Emit", + "mojang_textures:mojang_api_textures_provider:after_request", + expectedResult, + nil, + ).Once() result, err := suite.Provider.GetTextures("aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa") @@ -69,11 +75,19 @@ func (suite *mojangApiTexturesProviderTestSuite) TestGetTextures() { } func (suite *mojangApiTexturesProviderTestSuite) TestGetTexturesWithError() { + var expectedResponse *mojang.SignedTexturesResponse expectedError := &mojang.TooManyRequestsError{} suite.MojangApi.On("UuidToTextures", "aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa", true).Once().Return(nil, expectedError) - suite.Logger.On("IncCounter", "mojang_textures.textures.request", int64(1)).Once() - suite.Logger.On("RecordTimer", "mojang_textures.textures.request_time", mock.Anything).Once() + suite.Emitter.On("Emit", + "mojang_textures:mojang_api_textures_provider:before_request", + "aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa", + ).Once() + suite.Emitter.On("Emit", + "mojang_textures:mojang_api_textures_provider:after_request", + expectedResponse, + expectedError, + ).Once() result, err := suite.Provider.GetTextures("aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa") diff --git a/mojangtextures/mojang_textures.go b/mojangtextures/mojang_textures.go index 2212cd7..b41dbe8 100644 --- a/mojangtextures/mojang_textures.go +++ b/mojangtextures/mojang_textures.go @@ -2,15 +2,9 @@ package mojangtextures import ( "errors" - "net" - "net/url" "regexp" "strings" "sync" - "syscall" - "time" - - "github.com/mono83/slf/wd" "github.com/elyby/chrly/api/mojang" ) @@ -77,40 +71,45 @@ type TexturesProvider interface { GetTextures(uuid string) (*mojang.SignedTexturesResponse, error) } +type Emitter interface { + Emit(name string, args ...interface{}) +} + type Provider struct { + Emitter UUIDsProvider TexturesProvider Storage - Logger wd.Watchdog onFirstCall sync.Once *broadcaster } +// TODO: move cache events on the corresponding level + func (ctx *Provider) GetForUsername(username string) (*mojang.SignedTexturesResponse, error) { ctx.onFirstCall.Do(func() { ctx.broadcaster = createBroadcaster() }) if !allowedUsernamesRegex.MatchString(username) { - ctx.Logger.IncCounter("mojang_textures.invalid_username", 1) return nil, errors.New("invalid username") } username = strings.ToLower(username) - ctx.Logger.IncCounter("mojang_textures.request", 1) + ctx.Emit("mojang_textures:call") uuid, err := ctx.Storage.GetUuid(username) if err == nil && uuid == "" { - ctx.Logger.IncCounter("mojang_textures.usernames.cache_hit_nil", 1) + ctx.Emit("mojang_textures:usernames:cache_hit_nil") return nil, nil } if uuid != "" { - ctx.Logger.IncCounter("mojang_textures.usernames.cache_hit", 1) + ctx.Emit("mojang_textures:usernames:cache_hit") textures, err := ctx.Storage.GetTextures(uuid) if err == nil { - ctx.Logger.IncCounter("mojang_textures.textures.cache_hit", 1) + ctx.Emit("mojang_textures:textures:cache_hit") return textures, nil } } @@ -120,7 +119,7 @@ func (ctx *Provider) GetForUsername(username string) (*mojang.SignedTexturesResp if isFirstListener { go ctx.getResultAndBroadcast(username, uuid) } else { - ctx.Logger.IncCounter("mojang_textures.already_scheduled", 1) + ctx.Emit("mojang_textures:already_processing") } result := <-resultChan @@ -129,19 +128,19 @@ func (ctx *Provider) GetForUsername(username string) (*mojang.SignedTexturesResp } func (ctx *Provider) getResultAndBroadcast(username string, uuid string) { - start := time.Now() + ctx.Emit("mojang_textures:before_get_result") result := ctx.getResult(username, uuid) ctx.broadcaster.BroadcastAndRemove(username, result) - ctx.Logger.RecordTimer("mojang_textures.result_time", time.Since(start)) + ctx.Emit("mojang_textures:after_get_result") } func (ctx *Provider) getResult(username string, uuid string) *broadcastResult { if uuid == "" { profile, err := ctx.UUIDsProvider.GetUuid(username) if err != nil { - ctx.handleMojangApiResponseError(err, "usernames") + ctx.Emit("mojang_textures:usernames:error", err) return &broadcastResult{nil, err} } @@ -153,16 +152,16 @@ func (ctx *Provider) getResult(username string, uuid string) *broadcastResult { _ = ctx.Storage.StoreUuid(username, uuid) if uuid == "" { - ctx.Logger.IncCounter("mojang_textures.usernames.uuid_miss", 1) + ctx.Emit("mojang_textures:usernames:uuid_miss") return &broadcastResult{nil, nil} } - ctx.Logger.IncCounter("mojang_textures.usernames.uuid_hit", 1) + ctx.Emit("mojang_textures:usernames:uuid_hit") } textures, err := ctx.TexturesProvider.GetTextures(uuid) if err != nil { - ctx.handleMojangApiResponseError(err, "textures") + ctx.Emit("mojang_textures:textures:error", err) return &broadcastResult{nil, err} } @@ -171,55 +170,10 @@ func (ctx *Provider) getResult(username string, uuid string) *broadcastResult { ctx.Storage.StoreTextures(uuid, textures) if textures != nil { - ctx.Logger.IncCounter("mojang_textures.usernames.textures_hit", 1) + ctx.Emit("mojang_textures:textures:hit") } else { - ctx.Logger.IncCounter("mojang_textures.usernames.textures_miss", 1) + ctx.Emit("mojang_textures:textures:miss") } return &broadcastResult{textures, nil} } - -func (ctx *Provider) handleMojangApiResponseError(err error, threadName string) { - errParam := wd.ErrParam(err) - threadParam := wd.NameParam(threadName) - - ctx.Logger.Debug(":name: Got response error :err", threadParam, errParam) - - switch err.(type) { - case mojang.ResponseError: - if _, ok := err.(*mojang.BadRequestError); ok { - ctx.Logger.Warning(":name: Got 400 Bad Request :err", threadParam, errParam) - return - } - - if _, ok := err.(*mojang.ForbiddenError); ok { - ctx.Logger.Warning(":name: Got 403 Forbidden :err", threadParam, errParam) - return - } - - if _, ok := err.(*mojang.TooManyRequestsError); ok { - ctx.Logger.Warning(":name: Got 429 Too Many Requests :err", threadParam, errParam) - return - } - - 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 - } - } - - ctx.Logger.Emergency(":name: Unknown Mojang response error: :err", threadParam, errParam) -} diff --git a/mojangtextures/mojang_textures_test.go b/mojangtextures/mojang_textures_test.go index e9c2ce2..a9aef44 100644 --- a/mojangtextures/mojang_textures_test.go +++ b/mojangtextures/mojang_textures_test.go @@ -2,10 +2,7 @@ package mojangtextures import ( "errors" - "net" - "net/url" "sync" - "syscall" "testing" "time" @@ -14,7 +11,6 @@ import ( "github.com/stretchr/testify/suite" "github.com/elyby/chrly/api/mojang" - mocks "github.com/elyby/chrly/tests" ) func TestBroadcaster(t *testing.T) { @@ -86,6 +82,14 @@ func TestBroadcaster(t *testing.T) { }) } +type mockEmitter struct { + mock.Mock +} + +func (e *mockEmitter) Emit(name string, args ...interface{}) { + e.Called(append([]interface{}{name}, args...)...) +} + type mockUuidsProvider struct { mock.Mock } @@ -145,32 +149,31 @@ func (m *mockStorage) StoreTextures(uuid string, textures *mojang.SignedTextures type providerTestSuite struct { suite.Suite Provider *Provider + Emitter *mockEmitter UuidsProvider *mockUuidsProvider TexturesProvider *mockTexturesProvider Storage *mockStorage - Logger *mocks.WdMock } func (suite *providerTestSuite) SetupTest() { + suite.Emitter = &mockEmitter{} suite.UuidsProvider = &mockUuidsProvider{} suite.TexturesProvider = &mockTexturesProvider{} suite.Storage = &mockStorage{} - suite.Logger = &mocks.WdMock{} suite.Provider = &Provider{ + Emitter: suite.Emitter, UUIDsProvider: suite.UuidsProvider, TexturesProvider: suite.TexturesProvider, Storage: suite.Storage, - Logger: suite.Logger, } } func (suite *providerTestSuite) TearDownTest() { - // time.Sleep(10 * time.Millisecond) // Add delay to let finish all goroutines before assert mocks calls + suite.Emitter.AssertExpectations(suite.T()) suite.UuidsProvider.AssertExpectations(suite.T()) suite.TexturesProvider.AssertExpectations(suite.T()) suite.Storage.AssertExpectations(suite.T()) - suite.Logger.AssertExpectations(suite.T()) } func TestProvider(t *testing.T) { @@ -180,10 +183,11 @@ func TestProvider(t *testing.T) { func (suite *providerTestSuite) TestGetForUsernameWithoutAnyCache() { expectedResult := &mojang.SignedTexturesResponse{Id: "aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa", Name: "username"} - suite.Logger.On("IncCounter", "mojang_textures.request", int64(1)).Once() - suite.Logger.On("IncCounter", "mojang_textures.usernames.uuid_hit", int64(1)).Once() - suite.Logger.On("IncCounter", "mojang_textures.usernames.textures_hit", int64(1)).Once() - suite.Logger.On("RecordTimer", "mojang_textures.result_time", mock.Anything).Once() + suite.Emitter.On("Emit", "mojang_textures:call").Once() + suite.Emitter.On("Emit", "mojang_textures:before_get_result").Once() + suite.Emitter.On("Emit", "mojang_textures:usernames:uuid_hit").Once() + suite.Emitter.On("Emit", "mojang_textures:textures:hit").Once() + suite.Emitter.On("Emit", "mojang_textures:after_get_result").Once() suite.Storage.On("GetUuid", "username").Once().Return("", &ValueNotFound{}) suite.Storage.On("StoreUuid", "username", "aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa").Once().Return(nil) @@ -204,10 +208,11 @@ func (suite *providerTestSuite) TestGetForUsernameWithoutAnyCache() { func (suite *providerTestSuite) TestGetForUsernameWithCachedUuid() { expectedResult := &mojang.SignedTexturesResponse{Id: "aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa", Name: "username"} - suite.Logger.On("IncCounter", "mojang_textures.request", int64(1)).Once() - suite.Logger.On("IncCounter", "mojang_textures.usernames.cache_hit", int64(1)).Once() - suite.Logger.On("IncCounter", "mojang_textures.usernames.textures_hit", int64(1)).Once() - suite.Logger.On("RecordTimer", "mojang_textures.result_time", mock.Anything).Once() + suite.Emitter.On("Emit", "mojang_textures:call").Once() + suite.Emitter.On("Emit", "mojang_textures:usernames:cache_hit").Once() + suite.Emitter.On("Emit", "mojang_textures:before_get_result").Once() + suite.Emitter.On("Emit", "mojang_textures:textures:hit").Once() + suite.Emitter.On("Emit", "mojang_textures:after_get_result").Once() suite.Storage.On("GetUuid", "username").Once().Return("aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa", nil) suite.Storage.On("GetTextures", "aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa").Once().Return(nil, &ValueNotFound{}) @@ -224,9 +229,9 @@ func (suite *providerTestSuite) TestGetForUsernameWithCachedUuid() { func (suite *providerTestSuite) TestGetForUsernameWithFullyCachedResult() { expectedResult := &mojang.SignedTexturesResponse{Id: "aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa", Name: "username"} - suite.Logger.On("IncCounter", "mojang_textures.request", int64(1)).Once() - suite.Logger.On("IncCounter", "mojang_textures.usernames.cache_hit", int64(1)).Once() - suite.Logger.On("IncCounter", "mojang_textures.textures.cache_hit", int64(1)).Once() + suite.Emitter.On("Emit", "mojang_textures:call").Once() + suite.Emitter.On("Emit", "mojang_textures:usernames:cache_hit").Once() + suite.Emitter.On("Emit", "mojang_textures:textures:cache_hit").Once() suite.Storage.On("GetUuid", "username").Once().Return("aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa", nil) suite.Storage.On("GetTextures", "aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa").Once().Return(expectedResult, nil) @@ -238,8 +243,8 @@ func (suite *providerTestSuite) TestGetForUsernameWithFullyCachedResult() { } func (suite *providerTestSuite) TestGetForUsernameWithCachedUnknownUuid() { - suite.Logger.On("IncCounter", "mojang_textures.request", int64(1)).Once() - suite.Logger.On("IncCounter", "mojang_textures.usernames.cache_hit_nil", int64(1)).Once() + suite.Emitter.On("Emit", "mojang_textures:call").Once() + suite.Emitter.On("Emit", "mojang_textures:usernames:cache_hit_nil").Once() suite.Storage.On("GetUuid", "username").Once().Return("", nil) @@ -250,9 +255,10 @@ func (suite *providerTestSuite) TestGetForUsernameWithCachedUnknownUuid() { } func (suite *providerTestSuite) TestGetForUsernameWhichHasNoMojangAccount() { - suite.Logger.On("IncCounter", "mojang_textures.request", int64(1)).Once() - suite.Logger.On("IncCounter", "mojang_textures.usernames.uuid_miss", int64(1)).Once() - suite.Logger.On("RecordTimer", "mojang_textures.result_time", mock.Anything).Once() + suite.Emitter.On("Emit", "mojang_textures:call").Once() + suite.Emitter.On("Emit", "mojang_textures:before_get_result").Once() + suite.Emitter.On("Emit", "mojang_textures:usernames:uuid_miss").Once() + suite.Emitter.On("Emit", "mojang_textures:after_get_result").Once() suite.Storage.On("GetUuid", "username").Once().Return("", &ValueNotFound{}) suite.Storage.On("StoreUuid", "username", "").Once().Return(nil) @@ -268,10 +274,11 @@ func (suite *providerTestSuite) TestGetForUsernameWhichHasNoMojangAccount() { func (suite *providerTestSuite) TestGetForUsernameWhichHasMojangAccountButHasNoMojangSkin() { var expectedResult *mojang.SignedTexturesResponse - suite.Logger.On("IncCounter", "mojang_textures.request", int64(1)).Once() - suite.Logger.On("IncCounter", "mojang_textures.usernames.uuid_hit", int64(1)).Once() - suite.Logger.On("IncCounter", "mojang_textures.usernames.textures_miss", int64(1)).Once() - suite.Logger.On("RecordTimer", "mojang_textures.result_time", mock.Anything).Once() + suite.Emitter.On("Emit", "mojang_textures:call").Once() + suite.Emitter.On("Emit", "mojang_textures:before_get_result").Once() + suite.Emitter.On("Emit", "mojang_textures:usernames:uuid_hit").Once() + suite.Emitter.On("Emit", "mojang_textures:textures:miss").Once() + suite.Emitter.On("Emit", "mojang_textures:after_get_result").Once() suite.Storage.On("GetUuid", "username").Once().Return("", &ValueNotFound{}) suite.Storage.On("StoreUuid", "username", "aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa").Once().Return(nil) @@ -292,11 +299,12 @@ func (suite *providerTestSuite) TestGetForUsernameWhichHasMojangAccountButHasNoM func (suite *providerTestSuite) TestGetForTheSameUsernames() { expectedResult := &mojang.SignedTexturesResponse{Id: "aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa", Name: "username"} - suite.Logger.On("IncCounter", "mojang_textures.request", int64(1)).Twice() - suite.Logger.On("IncCounter", "mojang_textures.already_scheduled", int64(1)).Once() - suite.Logger.On("IncCounter", "mojang_textures.usernames.uuid_hit", int64(1)).Once() - suite.Logger.On("IncCounter", "mojang_textures.usernames.textures_hit", int64(1)).Once() - suite.Logger.On("RecordTimer", "mojang_textures.result_time", mock.Anything).Once() + suite.Emitter.On("Emit", "mojang_textures:call").Twice() + suite.Emitter.On("Emit", "mojang_textures:already_processing").Once() + suite.Emitter.On("Emit", "mojang_textures:before_get_result").Once() + suite.Emitter.On("Emit", "mojang_textures:usernames:uuid_hit").Once() + suite.Emitter.On("Emit", "mojang_textures:textures:hit").Once() + suite.Emitter.On("Emit", "mojang_textures:after_get_result").Once() suite.Storage.On("GetUuid", "username").Twice().Return("", &ValueNotFound{}) suite.Storage.On("StoreUuid", "username", "aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa").Once().Return(nil) @@ -326,114 +334,45 @@ func (suite *providerTestSuite) TestGetForTheSameUsernames() { } func (suite *providerTestSuite) TestGetForNotAllowedMojangUsername() { - suite.Logger.On("IncCounter", "mojang_textures.invalid_username", int64(1)).Once() - result, err := suite.Provider.GetForUsername("Not allowed") suite.Assert().Error(err, "invalid username") suite.Assert().Nil(result) } -type timeoutError struct { -} +func (suite *providerTestSuite) TestGetErrorFromUuidsProvider() { + err := errors.New("mock error") -func (*timeoutError) Error() string { return "timeout error" } -func (*timeoutError) Timeout() bool { return true } -func (*timeoutError) Temporary() bool { return false } + suite.Emitter.On("Emit", "mojang_textures:call").Once() + suite.Emitter.On("Emit", "mojang_textures:before_get_result").Once() + suite.Emitter.On("Emit", "mojang_textures:usernames:error", err).Once() + suite.Emitter.On("Emit", "mojang_textures:after_get_result").Once() -var expectedErrors = []error{ - &mojang.BadRequestError{}, - &mojang.ForbiddenError{}, - &mojang.TooManyRequestsError{}, - &mojang.ServerError{}, - &timeoutError{}, - &url.Error{Op: "GET", URL: "http://localhost"}, - &net.OpError{Op: "read"}, - &net.OpError{Op: "dial"}, - syscall.ECONNREFUSED, -} + suite.Storage.On("GetUuid", "username").Once().Return("", &ValueNotFound{}) + suite.UuidsProvider.On("GetUuid", "username").Once().Return(nil, err) -func (suite *providerTestSuite) TestShouldNotLogErrorWhenExpectedErrorReturnedFromUsernameToUuidRequest() { - suite.Logger.On("IncCounter", mock.Anything, mock.Anything) - suite.Logger.On("RecordTimer", mock.Anything, mock.Anything) - suite.Logger.On("Debug", ":name: Got response error :err", mock.Anything, mock.Anything).Times(len(expectedErrors)) - suite.Logger.On("Warning", ":name: Got 400 Bad Request :err", mock.Anything, mock.Anything).Once() - suite.Logger.On("Warning", ":name: Got 403 Forbidden :err", mock.Anything, mock.Anything).Once() - suite.Logger.On("Warning", ":name: Got 429 Too Many Requests :err", mock.Anything, mock.Anything).Once() - - suite.Storage.On("GetUuid", "username").Return("", &ValueNotFound{}) - - for _, err := range expectedErrors { - suite.UuidsProvider.On("GetUuid", "username").Once().Return(nil, err) - - result, err := suite.Provider.GetForUsername("username") - suite.Assert().Nil(result) - suite.Assert().NotNil(err) - suite.UuidsProvider.AssertExpectations(suite.T()) - suite.UuidsProvider.ExpectedCalls = nil // https://github.com/stretchr/testify/issues/558#issuecomment-372112364 - } -} - -func (suite *providerTestSuite) TestShouldLogEmergencyOnUnexpectedErrorReturnedFromUsernameToUuidRequest() { - suite.Logger.On("IncCounter", mock.Anything, mock.Anything) - suite.Logger.On("RecordTimer", mock.Anything, mock.Anything) - suite.Logger.On("Debug", ":name: Got response error :err", mock.Anything, mock.Anything).Once() - suite.Logger.On("Emergency", ":name: Unknown Mojang response error: :err", mock.Anything, mock.Anything).Once() - - suite.Storage.On("GetUuid", "username").Return("", &ValueNotFound{}) - - suite.UuidsProvider.On("GetUuid", "username").Once().Return(nil, errors.New("unexpected error")) - - result, err := suite.Provider.GetForUsername("username") + result, resErr := suite.Provider.GetForUsername("username") suite.Assert().Nil(result) - suite.Assert().NotNil(err) + suite.Assert().Equal(err, resErr) } -func (suite *providerTestSuite) TestShouldNotLogErrorWhenExpectedErrorReturnedFromUuidToTexturesRequest() { - suite.Logger.On("IncCounter", mock.Anything, mock.Anything) - suite.Logger.On("RecordTimer", mock.Anything, mock.Anything) - suite.Logger.On("Debug", ":name: Got response error :err", mock.Anything, mock.Anything).Times(len(expectedErrors)) - suite.Logger.On("Warning", ":name: Got 400 Bad Request :err", mock.Anything, mock.Anything).Once() - suite.Logger.On("Warning", ":name: Got 403 Forbidden :err", mock.Anything, mock.Anything).Once() - suite.Logger.On("Warning", ":name: Got 429 Too Many Requests :err", mock.Anything, mock.Anything).Once() +func (suite *providerTestSuite) TestGetErrorFromTexturesProvider() { + err := errors.New("mock error") + + suite.Emitter.On("Emit", "mojang_textures:call").Once() + suite.Emitter.On("Emit", "mojang_textures:before_get_result").Once() + suite.Emitter.On("Emit", "mojang_textures:usernames:uuid_hit").Once() + suite.Emitter.On("Emit", "mojang_textures:textures:error", err).Once() + suite.Emitter.On("Emit", "mojang_textures:after_get_result").Once() suite.Storage.On("GetUuid", "username").Return("", &ValueNotFound{}) suite.Storage.On("StoreUuid", "username", "aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa").Return(nil) - // suite.Storage.On("GetTextures", "aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa").Return(nil, &ValueNotFound{}) - // suite.Storage.On("StoreTextures", "aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa", (*mojang.SignedTexturesResponse)(nil)) - - for _, err := range expectedErrors { - suite.UuidsProvider.On("GetUuid", "username").Once().Return(&mojang.ProfileInfo{ - Id: "aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa", - Name: "username", - }, nil) - suite.TexturesProvider.On("GetTextures", "aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa").Once().Return(nil, err) - - result, err := suite.Provider.GetForUsername("username") - suite.Assert().Nil(result) - suite.Assert().NotNil(err) - suite.UuidsProvider.AssertExpectations(suite.T()) - suite.TexturesProvider.AssertExpectations(suite.T()) - suite.UuidsProvider.ExpectedCalls = nil // https://github.com/stretchr/testify/issues/558#issuecomment-372112364 - suite.TexturesProvider.ExpectedCalls = nil // https://github.com/stretchr/testify/issues/558#issuecomment-372112364 - } -} - -func (suite *providerTestSuite) TestShouldLogEmergencyOnUnexpectedErrorReturnedFromUuidToTexturesRequest() { - suite.Logger.On("IncCounter", mock.Anything, mock.Anything) - suite.Logger.On("RecordTimer", mock.Anything, mock.Anything) - suite.Logger.On("Debug", ":name: Got response error :err", mock.Anything, mock.Anything).Once() - suite.Logger.On("Emergency", ":name: Unknown Mojang response error: :err", mock.Anything, mock.Anything).Once() - - suite.Storage.On("GetUuid", "username").Return("", &ValueNotFound{}) - suite.Storage.On("StoreUuid", "username", "aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa").Return(nil) - suite.UuidsProvider.On("GetUuid", "username").Once().Return(&mojang.ProfileInfo{ Id: "aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa", Name: "username", }, nil) - suite.TexturesProvider.On("GetTextures", "aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa").Once().Return(nil, errors.New("unexpected error")) + suite.TexturesProvider.On("GetTextures", "aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa").Once().Return(nil, err) - result, err := suite.Provider.GetForUsername("username") + result, resErr := suite.Provider.GetForUsername("username") suite.Assert().Nil(result) - suite.Assert().NotNil(err) + suite.Assert().Equal(err, resErr) } diff --git a/mojangtextures/remote_api_uuids_provider.go b/mojangtextures/remote_api_uuids_provider.go index 4d05b49..b468dd0 100644 --- a/mojangtextures/remote_api_uuids_provider.go +++ b/mojangtextures/remote_api_uuids_provider.go @@ -2,16 +2,13 @@ package mojangtextures import ( "encoding/json" - "github.com/elyby/chrly/version" "io/ioutil" "net/http" . "net/url" "path" - "time" - - "github.com/mono83/slf/wd" "github.com/elyby/chrly/api/mojang" + "github.com/elyby/chrly/version" ) var HttpClient = &http.Client{ @@ -21,24 +18,23 @@ var HttpClient = &http.Client{ } type RemoteApiUuidsProvider struct { + Emitter Url URL - Logger wd.Watchdog } func (ctx *RemoteApiUuidsProvider) GetUuid(username string) (*mojang.ProfileInfo, error) { - ctx.Logger.IncCounter("mojang_textures.usernames.request", 1) - url := ctx.Url url.Path = path.Join(url.Path, username) + urlStr := url.String() - request, _ := http.NewRequest("GET", url.String(), nil) + request, _ := http.NewRequest("GET", urlStr, nil) request.Header.Add("Accept", "application/json") // Change default User-Agent to allow specify "Username -> UUID at time" Mojang's api endpoint request.Header.Add("User-Agent", "Chrly/"+version.Version()) - start := time.Now() + ctx.Emit("mojang_textures:remote_api_uuids_provider:before_request", urlStr) response, err := HttpClient.Do(request) - ctx.Logger.RecordTimer("mojang_textures.usernames.request_time", time.Since(start)) + ctx.Emit("mojang_textures:remote_api_uuids_provider:after_request", response, err) if err != nil { return nil, err } diff --git a/mojangtextures/remote_api_uuids_provider_test.go b/mojangtextures/remote_api_uuids_provider_test.go index b47edca..166b432 100644 --- a/mojangtextures/remote_api_uuids_provider_test.go +++ b/mojangtextures/remote_api_uuids_provider_test.go @@ -3,21 +3,19 @@ package mojangtextures import ( "net" "net/http" - "net/url" + . "net/url" "testing" "github.com/h2non/gock" "github.com/stretchr/testify/mock" "github.com/stretchr/testify/suite" - - mocks "github.com/elyby/chrly/tests" ) type remoteApiUuidsProviderTestSuite struct { suite.Suite Provider *RemoteApiUuidsProvider - Logger *mocks.WdMock + Emitter *mockEmitter } func (suite *remoteApiUuidsProviderTestSuite) SetupSuite() { @@ -28,14 +26,14 @@ func (suite *remoteApiUuidsProviderTestSuite) SetupSuite() { } func (suite *remoteApiUuidsProviderTestSuite) SetupTest() { - suite.Logger = &mocks.WdMock{} + suite.Emitter = &mockEmitter{} suite.Provider = &RemoteApiUuidsProvider{ - Logger: suite.Logger, + Emitter: suite.Emitter, } } func (suite *remoteApiUuidsProviderTestSuite) TearDownTest() { - suite.Logger.AssertExpectations(suite.T()) + suite.Emitter.AssertExpectations(suite.T()) gock.Off() } @@ -44,8 +42,12 @@ func TestRemoteApiUuidsProvider(t *testing.T) { } func (suite *remoteApiUuidsProviderTestSuite) TestGetUuidForValidUsername() { - suite.Logger.On("IncCounter", "mojang_textures.usernames.request", int64(1)).Once() - suite.Logger.On("RecordTimer", "mojang_textures.usernames.request_time", mock.Anything).Once() + suite.Emitter.On("Emit", "mojang_textures:remote_api_uuids_provider:before_request", "http://example.com/subpath/username").Once() + suite.Emitter.On("Emit", + "mojang_textures:remote_api_uuids_provider:after_request", + mock.AnythingOfType("*http.Response"), + nil, + ).Once() gock.New("http://example.com"). Get("/subpath/username"). @@ -68,8 +70,12 @@ func (suite *remoteApiUuidsProviderTestSuite) TestGetUuidForValidUsername() { } func (suite *remoteApiUuidsProviderTestSuite) TestGetUuidForNotExistsUsername() { - suite.Logger.On("IncCounter", "mojang_textures.usernames.request", int64(1)).Once() - suite.Logger.On("RecordTimer", "mojang_textures.usernames.request_time", mock.Anything).Once() + suite.Emitter.On("Emit", "mojang_textures:remote_api_uuids_provider:before_request", "http://example.com/subpath/username").Once() + suite.Emitter.On("Emit", + "mojang_textures:remote_api_uuids_provider:after_request", + mock.AnythingOfType("*http.Response"), + nil, + ).Once() gock.New("http://example.com"). Get("/subpath/username"). @@ -84,8 +90,12 @@ func (suite *remoteApiUuidsProviderTestSuite) TestGetUuidForNotExistsUsername() } func (suite *remoteApiUuidsProviderTestSuite) TestGetUuidForNon20xResponse() { - suite.Logger.On("IncCounter", "mojang_textures.usernames.request", int64(1)).Once() - suite.Logger.On("RecordTimer", "mojang_textures.usernames.request_time", mock.Anything).Once() + suite.Emitter.On("Emit", "mojang_textures:remote_api_uuids_provider:before_request", "http://example.com/subpath/username").Once() + suite.Emitter.On("Emit", + "mojang_textures:remote_api_uuids_provider:after_request", + mock.AnythingOfType("*http.Response"), + nil, + ).Once() gock.New("http://example.com"). Get("/subpath/username"). @@ -101,8 +111,12 @@ func (suite *remoteApiUuidsProviderTestSuite) TestGetUuidForNon20xResponse() { } func (suite *remoteApiUuidsProviderTestSuite) TestGetUuidForNotSuccessRequest() { - suite.Logger.On("IncCounter", "mojang_textures.usernames.request", int64(1)).Once() - suite.Logger.On("RecordTimer", "mojang_textures.usernames.request_time", mock.Anything).Once() + suite.Emitter.On("Emit", "mojang_textures:remote_api_uuids_provider:before_request", "http://example.com/subpath/username").Once() + suite.Emitter.On("Emit", + "mojang_textures:remote_api_uuids_provider:after_request", + mock.AnythingOfType("*http.Response"), + mock.AnythingOfType("*url.Error"), + ).Once() expectedError := &net.OpError{Op: "dial"} @@ -116,15 +130,19 @@ func (suite *remoteApiUuidsProviderTestSuite) TestGetUuidForNotSuccessRequest() assert := suite.Assert() assert.Nil(result) if assert.Error(err) { - assert.IsType(&url.Error{}, err) - casterErr, _ := err.(*url.Error) + assert.IsType(&Error{}, err) + casterErr, _ := err.(*Error) assert.Equal(expectedError, casterErr.Err) } } func (suite *remoteApiUuidsProviderTestSuite) TestGetUuidForInvalidSuccessResponse() { - suite.Logger.On("IncCounter", "mojang_textures.usernames.request", int64(1)).Once() - suite.Logger.On("RecordTimer", "mojang_textures.usernames.request_time", mock.Anything).Once() + suite.Emitter.On("Emit", "mojang_textures:remote_api_uuids_provider:before_request", "http://example.com/subpath/username").Once() + suite.Emitter.On("Emit", + "mojang_textures:remote_api_uuids_provider:after_request", + mock.AnythingOfType("*http.Response"), + nil, + ).Once() gock.New("http://example.com"). Get("/subpath/username"). @@ -139,8 +157,8 @@ func (suite *remoteApiUuidsProviderTestSuite) TestGetUuidForInvalidSuccessRespon assert.Error(err) } -func shouldParseUrl(rawUrl string) url.URL { - url, err := url.Parse(rawUrl) +func shouldParseUrl(rawUrl string) URL { + url, err := Parse(rawUrl) if err != nil { panic(err) } From db728451f86e680ab51e95490f051d15f333ccb8 Mon Sep 17 00:00:00 2001 From: ErickSkrauch Date: Sat, 8 Feb 2020 14:31:47 +0300 Subject: [PATCH 03/18] Implemented event dispatcher --- Gopkg.lock | 9 +++++++++ Gopkg.toml | 4 ++++ bootstrap/bootstrap.go | 7 ++++++- cmd/serve.go | 9 ++++++--- cmd/worker.go | 6 ++++-- dispatcher/dispatcher.go | 26 ++++++++++++++++++++++++++ 6 files changed, 55 insertions(+), 6 deletions(-) create mode 100644 dispatcher/dispatcher.go diff --git a/Gopkg.lock b/Gopkg.lock index 8416f5d..1c46e89 100644 --- a/Gopkg.lock +++ b/Gopkg.lock @@ -14,6 +14,14 @@ revision = "f6df55f235c24f236d11dbcf665249a59ac2021f" version = "1.1" +[[projects]] + branch = "master" + digest = "1:33c6f6a0ee7d594d07ad9b67e93266f8a859ab2ddd882f8be19207162f40cce8" + name = "github.com/asaskevich/EventBus" + packages = ["."] + pruneopts = "" + revision = "d46933a94f05c6657d7b923fcf5ac563ee37ec79" + [[projects]] digest = "1:c7b11da9bf0707e6920e1b361fbbbbe9b277ef3a198377baa4527f6e31049be0" name = "github.com/certifi/gocertifi" @@ -301,6 +309,7 @@ input-imports = [ "github.com/SermoDigital/jose/crypto", "github.com/SermoDigital/jose/jws", + "github.com/asaskevich/EventBus", "github.com/getsentry/raven-go", "github.com/gorilla/mux", "github.com/h2non/gock", diff --git a/Gopkg.toml b/Gopkg.toml index a260730..e851485 100644 --- a/Gopkg.toml +++ b/Gopkg.toml @@ -36,6 +36,10 @@ ignored = ["github.com/elyby/chrly"] name = "github.com/tevino/abool" branch = "master" +[[constraint]] + branch = "master" + name = "github.com/asaskevich/EventBus" + # Testing dependencies [[constraint]] diff --git a/bootstrap/bootstrap.go b/bootstrap/bootstrap.go index 39a4b51..b93f540 100644 --- a/bootstrap/bootstrap.go +++ b/bootstrap/bootstrap.go @@ -1,7 +1,6 @@ package bootstrap import ( - "github.com/elyby/chrly/http" "net/url" "os" "time" @@ -14,6 +13,8 @@ import ( "github.com/mono83/slf/wd" "github.com/spf13/viper" + "github.com/elyby/chrly/dispatcher" + "github.com/elyby/chrly/http" "github.com/elyby/chrly/mojangtextures" "github.com/elyby/chrly/version" ) @@ -93,3 +94,7 @@ func CreateMojangUUIDsProvider(emitter http.Emitter) (mojangtextures.UUIDsProvid return uuidsProvider, nil } + +func CreateEventDispatcher() dispatcher.EventDispatcher { + return dispatcher.New() +} diff --git a/cmd/serve.go b/cmd/serve.go index 010b8a2..5d96bae 100644 --- a/cmd/serve.go +++ b/cmd/serve.go @@ -26,6 +26,8 @@ var serveCmd = &cobra.Command{ } logger.Info("Logger successfully initialized") + dispatcher := bootstrap.CreateEventDispatcher() + storageFactory := db.StorageFactory{Config: viper.GetViper()} logger.Info("Initializing skins repository") @@ -53,7 +55,7 @@ var serveCmd = &cobra.Command{ return } - uuidsProvider, err := bootstrap.CreateMojangUUIDsProvider(nil) + uuidsProvider, err := bootstrap.CreateMojangUUIDsProvider(dispatcher) if err != nil { logger.Emergency("Unable to parse remote url :err", wd.ErrParam(err)) return @@ -62,10 +64,10 @@ var serveCmd = &cobra.Command{ texturesStorage := mojangtextures.NewInMemoryTexturesStorage() texturesStorage.Start() mojangTexturesProvider := &mojangtextures.Provider{ - // TODO: configure emitter + Emitter: dispatcher, UUIDsProvider: uuidsProvider, TexturesProvider: &mojangtextures.MojangApiTexturesProvider{ - // TODO: configure emitter + Emitter: dispatcher, }, Storage: &mojangtextures.SeparatedStorage{ UuidsStorage: mojangUuidsRepository, @@ -76,6 +78,7 @@ var serveCmd = &cobra.Command{ address := fmt.Sprintf("%s:%d", viper.GetString("server.host"), viper.GetInt("server.port")) handler := (&http.Skinsystem{ + Emitter: dispatcher, SkinsRepo: skinsRepo, CapesRepo: capesRepo, MojangTexturesProvider: mojangTexturesProvider, diff --git a/cmd/worker.go b/cmd/worker.go index 8f3f22a..53b9f61 100644 --- a/cmd/worker.go +++ b/cmd/worker.go @@ -22,7 +22,9 @@ var workerCmd = &cobra.Command{ } logger.Info("Logger successfully initialized") - uuidsProvider, err := bootstrap.CreateMojangUUIDsProvider(logger) + dispatcher := bootstrap.CreateEventDispatcher() + + uuidsProvider, err := bootstrap.CreateMojangUUIDsProvider(dispatcher) if err != nil { logger.Emergency("Unable to parse remote url :err", wd.ErrParam(err)) return @@ -30,8 +32,8 @@ var workerCmd = &cobra.Command{ address := fmt.Sprintf("%s:%d", viper.GetString("server.host"), viper.GetInt("server.port")) handler := (&http.UUIDsWorker{ + Emitter: dispatcher, UUIDsProvider: uuidsProvider, - // TODO: configure emitter }).CreateHandler() finishChan := make(chan bool) diff --git a/dispatcher/dispatcher.go b/dispatcher/dispatcher.go new file mode 100644 index 0000000..e8d1515 --- /dev/null +++ b/dispatcher/dispatcher.go @@ -0,0 +1,26 @@ +package dispatcher + +import "github.com/asaskevich/EventBus" + +type EventDispatcher interface { + Subscribe(name string, fn interface{}) + Emit(name string, args ...interface{}) +} + +type LocalEventDispatcher struct { + bus EventBus.Bus +} + +func (d *LocalEventDispatcher) Subscribe(name string, fn interface{}) { + _ = d.bus.Subscribe(name, fn) +} + +func (d *LocalEventDispatcher) Emit(name string, args ...interface{}) { + d.bus.Publish(name, args...) +} + +func New() EventDispatcher { + return &LocalEventDispatcher{ + bus: EventBus.New(), + } +} From 40c53ea0d908bf5481bb8cbeb97e3c97a6e17d40 Mon Sep 17 00:00:00 2001 From: ErickSkrauch Date: Sun, 16 Feb 2020 13:23:47 +0300 Subject: [PATCH 04/18] Add stats reporter events listener, restore all events for http layer, rework authentication middleware and authenticator interface --- auth/jwt_test.go | 97 ------------- cmd/serve.go | 3 +- cmd/token.go | 6 +- dispatcher/dispatcher.go | 12 +- eventsubscribers/stats_reporter.go | 85 +++++++++++ eventsubscribers/stats_reporter_test.go | 178 ++++++++++++++++++++++++ http/http.go | 50 +++++++ http/http_test.go | 80 ++++++++++- {auth => http}/jwt.go | 30 ++-- http/jwt_test.go | 127 +++++++++++++++++ http/skinsystem.go | 53 ++----- http/skinsystem_test.go | 66 ++++++--- 12 files changed, 602 insertions(+), 185 deletions(-) delete mode 100644 auth/jwt_test.go create mode 100644 eventsubscribers/stats_reporter.go create mode 100644 eventsubscribers/stats_reporter_test.go rename {auth => http}/jwt.go (63%) create mode 100644 http/jwt_test.go diff --git a/auth/jwt_test.go b/auth/jwt_test.go deleted file mode 100644 index 00fc65a..0000000 --- a/auth/jwt_test.go +++ /dev/null @@ -1,97 +0,0 @@ -package auth - -import ( - "net/http/httptest" - "testing" - - testify "github.com/stretchr/testify/assert" -) - -const jwt = "eyJhbGciOiJIUzI1NiIsInR5cCI6IkpXVCJ9.eyJzdWIiOiIxNTE2NjU4MTkzIiwic2NvcGVzIjoic2tpbiJ9.agbBS0qdyYMBaVfTZJAZcTTRgW1Y0kZty4H3N2JHBO8" - -func TestJwtAuth_NewToken_Success(t *testing.T) { - assert := testify.New(t) - - jwt := &JwtAuth{[]byte("secret")} - token, err := jwt.NewToken(SkinScope) - assert.Nil(err) - assert.NotNil(token) -} - -func TestJwtAuth_NewToken_KeyNotAvailable(t *testing.T) { - assert := testify.New(t) - - jwt := &JwtAuth{} - token, err := jwt.NewToken(SkinScope) - assert.Error(err, "signing key not available") - assert.Nil(token) -} - -func TestJwtAuth_Check_EmptyRequest(t *testing.T) { - assert := testify.New(t) - - req := httptest.NewRequest("POST", "http://localhost", nil) - jwt := &JwtAuth{[]byte("secret")} - - err := jwt.Check(req) - assert.IsType(&Unauthorized{}, err) - assert.EqualError(err, "Authentication header not presented") -} - -func TestJwtAuth_Check_NonBearer(t *testing.T) { - assert := testify.New(t) - - req := httptest.NewRequest("POST", "http://localhost", nil) - req.Header.Add("Authorization", "this is not jwt") - jwt := &JwtAuth{[]byte("secret")} - - err := jwt.Check(req) - assert.IsType(&Unauthorized{}, err) - assert.EqualError(err, "Cannot recognize JWT token in passed value") -} - -func TestJwtAuth_Check_BearerButNotJwt(t *testing.T) { - assert := testify.New(t) - - req := httptest.NewRequest("POST", "http://localhost", nil) - req.Header.Add("Authorization", "Bearer thisIs.Not.Jwt") - jwt := &JwtAuth{[]byte("secret")} - - err := jwt.Check(req) - assert.IsType(&Unauthorized{}, err) - assert.EqualError(err, "Cannot parse passed JWT token") -} - -func TestJwtAuth_Check_SecretNotAvailable(t *testing.T) { - assert := testify.New(t) - - req := httptest.NewRequest("POST", "http://localhost", nil) - req.Header.Add("Authorization", "Bearer " + jwt) - jwt := &JwtAuth{} - - err := jwt.Check(req) - assert.Error(err, "Signing key not set") -} - -func TestJwtAuth_Check_SecretInvalid(t *testing.T) { - assert := testify.New(t) - - req := httptest.NewRequest("POST", "http://localhost", nil) - req.Header.Add("Authorization", "Bearer " + jwt) - jwt := &JwtAuth{[]byte("this is another secret")} - - err := jwt.Check(req) - assert.IsType(&Unauthorized{}, err) - assert.EqualError(err, "JWT token have invalid signature. It may be corrupted or expired.") -} - -func TestJwtAuth_Check_Valid(t *testing.T) { - assert := testify.New(t) - - req := httptest.NewRequest("POST", "http://localhost", nil) - req.Header.Add("Authorization", "Bearer " + jwt) - jwt := &JwtAuth{[]byte("secret")} - - err := jwt.Check(req) - assert.Nil(err) -} diff --git a/cmd/serve.go b/cmd/serve.go index 5d96bae..31d0680 100644 --- a/cmd/serve.go +++ b/cmd/serve.go @@ -8,7 +8,6 @@ import ( "github.com/spf13/cobra" "github.com/spf13/viper" - "github.com/elyby/chrly/auth" "github.com/elyby/chrly/bootstrap" "github.com/elyby/chrly/db" "github.com/elyby/chrly/http" @@ -82,7 +81,7 @@ var serveCmd = &cobra.Command{ SkinsRepo: skinsRepo, CapesRepo: capesRepo, MojangTexturesProvider: mojangTexturesProvider, - Auth: &auth.JwtAuth{Key: []byte(viper.GetString("chrly.secret"))}, + Authenticator: &http.JwtAuth{Key: []byte(viper.GetString("chrly.secret"))}, TexturesExtraParamName: viper.GetString("textures.extra_param_name"), TexturesExtraParamValue: viper.GetString("textures.extra_param_value"), }).CreateHandler() diff --git a/cmd/token.go b/cmd/token.go index 2380d36..ba891fb 100644 --- a/cmd/token.go +++ b/cmd/token.go @@ -4,7 +4,7 @@ import ( "fmt" "log" - "github.com/elyby/chrly/auth" + "github.com/elyby/chrly/http" "github.com/spf13/cobra" "github.com/spf13/viper" @@ -14,8 +14,8 @@ var tokenCmd = &cobra.Command{ Use: "token", Short: "Creates a new token, which allows to interact with Chrly API", Run: func(cmd *cobra.Command, args []string) { - jwtAuth := &auth.JwtAuth{Key: []byte(viper.GetString("chrly.secret"))} - token, err := jwtAuth.NewToken(auth.SkinScope) + jwtAuth := &http.JwtAuth{Key: []byte(viper.GetString("chrly.secret"))} + token, err := jwtAuth.NewToken(http.SkinScope) if err != nil { log.Fatalf("Unable to create new token. The error is %v\n", err) } diff --git a/dispatcher/dispatcher.go b/dispatcher/dispatcher.go index e8d1515..8488202 100644 --- a/dispatcher/dispatcher.go +++ b/dispatcher/dispatcher.go @@ -3,20 +3,20 @@ package dispatcher import "github.com/asaskevich/EventBus" type EventDispatcher interface { - Subscribe(name string, fn interface{}) - Emit(name string, args ...interface{}) + Subscribe(topic string, fn interface{}) + Emit(topic string, args ...interface{}) } type LocalEventDispatcher struct { bus EventBus.Bus } -func (d *LocalEventDispatcher) Subscribe(name string, fn interface{}) { - _ = d.bus.Subscribe(name, fn) +func (d *LocalEventDispatcher) Subscribe(topic string, fn interface{}) { + _ = d.bus.Subscribe(topic, fn) } -func (d *LocalEventDispatcher) Emit(name string, args ...interface{}) { - d.bus.Publish(name, args...) +func (d *LocalEventDispatcher) Emit(topic string, args ...interface{}) { + d.bus.Publish(topic, args...) } func New() EventDispatcher { diff --git a/eventsubscribers/stats_reporter.go b/eventsubscribers/stats_reporter.go new file mode 100644 index 0000000..ad0e449 --- /dev/null +++ b/eventsubscribers/stats_reporter.go @@ -0,0 +1,85 @@ +package eventsubscribers + +import ( + "net/http" + "strings" + + "github.com/mono83/slf" + + "github.com/elyby/chrly/dispatcher" +) + +type StatsReporter struct { + Reporter slf.StatsReporter + Prefix string +} + +func (s *StatsReporter) ConfigureWithDispatcher(d dispatcher.EventDispatcher) { + d.Subscribe("skinsystem:before_request", s.handleBeforeRequest) + d.Subscribe("skinsystem:after_request", s.handleAfterRequest) + + d.Subscribe("authenticator:success", s.incCounterHandler("authentication.challenge")) // TODO: legacy, remove in v5 + d.Subscribe("authenticator:success", s.incCounterHandler("authentication.success")) + d.Subscribe("authentication:error", s.incCounterHandler("authentication.challenge")) // TODO: legacy, remove in v5 + d.Subscribe("authentication:error", s.incCounterHandler("authentication.failed")) +} + +func (s *StatsReporter) handleBeforeRequest(req *http.Request) { + var key string + m := req.Method + p := req.URL.Path + if p == "/skins" { + key = "skins.get_request" + } else if strings.HasPrefix(p, "/skins/") { + key = "skins.request" + } else if p == "/cloaks" { + key = "capes.get_request" + } else if strings.HasPrefix(p, "/cloaks/") { + key = "capes.request" + } else if strings.HasPrefix(p, "/textures/signed/") { + key = "signed_textures.request" + } else if strings.HasPrefix(p, "/textures/") { + key = "textures.request" + } else if m == http.MethodPost && p == "/api/skins" { + key = "api.skins.post.request" + } else if m == http.MethodDelete && strings.HasPrefix(p, "/api/skins/") { + key = "api.skins.delete.request" + } else { + return + } + + s.incCounter(key) +} + +func (s *StatsReporter) handleAfterRequest(req *http.Request, code int) { + var key string + m := req.Method + p := req.URL.Path + if m == http.MethodPost && p == "/api/skins" && code == http.StatusCreated { + key = "api.skins.post.success" + } else if m == http.MethodPost && p == "/api/skins" && code == http.StatusBadRequest { + key = "api.skins.post.validation_failed" + } else if m == http.MethodDelete && strings.HasPrefix(p, "/api/skins/") && code == http.StatusNoContent { + key = "api.skins.delete.success" + } else if m == http.MethodDelete && strings.HasPrefix(p, "/api/skins/") && code == http.StatusNotFound { + key = "api.skins.delete.not_found" + } else { + return + } + + s.incCounter(key) +} + +func (s *StatsReporter) incCounterHandler(name string) func(...interface{}) { + return func(...interface{}) { + s.incCounter(name) + } +} + +func (s *StatsReporter) incCounter(name string) { + s.Reporter.IncCounter(s.key(name), 1) +} + +func (s *StatsReporter) key(name string) string { + return strings.Join([]string{s.Prefix, name}, ".") +} diff --git a/eventsubscribers/stats_reporter_test.go b/eventsubscribers/stats_reporter_test.go new file mode 100644 index 0000000..7d0ea24 --- /dev/null +++ b/eventsubscribers/stats_reporter_test.go @@ -0,0 +1,178 @@ +package eventsubscribers + +import ( + "errors" + "net/http/httptest" + "testing" + + "github.com/elyby/chrly/dispatcher" + "github.com/elyby/chrly/tests" +) + +type StatsReporterTestCase struct { + Topic string + Args []interface{} + ExpectedCalls [][]interface{} +} + +var statsReporterTestCases = []*StatsReporterTestCase{ + // Before request + { + Topic: "skinsystem:before_request", + Args: []interface{}{httptest.NewRequest("GET", "http://localhost/skins/username", nil)}, + ExpectedCalls: [][]interface{}{ + {"IncCounter", "mock_prefix.skins.request", int64(1)}, + }, + }, + { + Topic: "skinsystem:before_request", + Args: []interface{}{httptest.NewRequest("GET", "http://localhost/skins?name=username", nil)}, + ExpectedCalls: [][]interface{}{ + {"IncCounter", "mock_prefix.skins.get_request", int64(1)}, + }, + }, + { + Topic: "skinsystem:before_request", + Args: []interface{}{httptest.NewRequest("GET", "http://localhost/cloaks/username", nil)}, + ExpectedCalls: [][]interface{}{ + {"IncCounter", "mock_prefix.capes.request", int64(1)}, + }, + }, + { + Topic: "skinsystem:before_request", + Args: []interface{}{httptest.NewRequest("GET", "http://localhost/cloaks?name=username", nil)}, + ExpectedCalls: [][]interface{}{ + {"IncCounter", "mock_prefix.capes.get_request", int64(1)}, + }, + }, + { + Topic: "skinsystem:before_request", + Args: []interface{}{httptest.NewRequest("GET", "http://localhost/textures/username", nil)}, + ExpectedCalls: [][]interface{}{ + {"IncCounter", "mock_prefix.textures.request", int64(1)}, + }, + }, + { + Topic: "skinsystem:before_request", + Args: []interface{}{httptest.NewRequest("GET", "http://localhost/textures/signed/username", nil)}, + ExpectedCalls: [][]interface{}{ + {"IncCounter", "mock_prefix.signed_textures.request", int64(1)}, + }, + }, + { + Topic: "skinsystem:before_request", + Args: []interface{}{httptest.NewRequest("POST", "http://localhost/api/skins", nil)}, + ExpectedCalls: [][]interface{}{ + {"IncCounter", "mock_prefix.api.skins.post.request", int64(1)}, + }, + }, + { + Topic: "skinsystem:before_request", + Args: []interface{}{httptest.NewRequest("DELETE", "http://localhost/api/skins/username", nil)}, + ExpectedCalls: [][]interface{}{ + {"IncCounter", "mock_prefix.api.skins.delete.request", int64(1)}, + }, + }, + { + Topic: "skinsystem:before_request", + Args: []interface{}{httptest.NewRequest("DELETE", "http://localhost/api/skins/id:1", nil)}, + ExpectedCalls: [][]interface{}{ + {"IncCounter", "mock_prefix.api.skins.delete.request", int64(1)}, + }, + }, + { + Topic: "skinsystem:before_request", + Args: []interface{}{httptest.NewRequest("GET", "http://localhost/unknown", nil)}, + ExpectedCalls: nil, + }, + // After request + { + Topic: "skinsystem:after_request", + Args: []interface{}{httptest.NewRequest("POST", "http://localhost/api/skins", nil), 201}, + ExpectedCalls: [][]interface{}{ + {"IncCounter", "mock_prefix.api.skins.post.success", int64(1)}, + }, + }, + { + Topic: "skinsystem:after_request", + Args: []interface{}{httptest.NewRequest("POST", "http://localhost/api/skins", nil), 400}, + ExpectedCalls: [][]interface{}{ + {"IncCounter", "mock_prefix.api.skins.post.validation_failed", int64(1)}, + }, + }, + { + Topic: "skinsystem:after_request", + Args: []interface{}{httptest.NewRequest("DELETE", "http://localhost/api/skins/username", nil), 204}, + ExpectedCalls: [][]interface{}{ + {"IncCounter", "mock_prefix.api.skins.delete.success", int64(1)}, + }, + }, + { + Topic: "skinsystem:after_request", + Args: []interface{}{httptest.NewRequest("DELETE", "http://localhost/api/skins/username", nil), 404}, + ExpectedCalls: [][]interface{}{ + {"IncCounter", "mock_prefix.api.skins.delete.not_found", int64(1)}, + }, + }, + { + Topic: "skinsystem:after_request", + Args: []interface{}{httptest.NewRequest("DELETE", "http://localhost/api/skins/id:1", nil), 204}, + ExpectedCalls: [][]interface{}{ + {"IncCounter", "mock_prefix.api.skins.delete.success", int64(1)}, + }, + }, + { + Topic: "skinsystem:after_request", + Args: []interface{}{httptest.NewRequest("DELETE", "http://localhost/api/skins/id:1", nil), 404}, + ExpectedCalls: [][]interface{}{ + {"IncCounter", "mock_prefix.api.skins.delete.not_found", int64(1)}, + }, + }, + { + Topic: "skinsystem:after_request", + Args: []interface{}{httptest.NewRequest("DELETE", "http://localhost/unknown", nil), 404}, + ExpectedCalls: nil, + }, + // Authenticator + { + Topic: "authenticator:success", + Args: []interface{}{}, + ExpectedCalls: [][]interface{}{ + {"IncCounter", "mock_prefix.authentication.challenge", int64(1)}, + {"IncCounter", "mock_prefix.authentication.success", int64(1)}, + }, + }, + { + Topic: "authentication:error", + Args: []interface{}{errors.New("error")}, + ExpectedCalls: [][]interface{}{ + {"IncCounter", "mock_prefix.authentication.challenge", int64(1)}, + {"IncCounter", "mock_prefix.authentication.failed", int64(1)}, + }, + }, +} + +func TestStatsReporter_handleHTTPRequest(t *testing.T) { + for _, c := range statsReporterTestCases { + t.Run(c.Topic, 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:]...).Once() + } + } + + reporter := &StatsReporter{ + Reporter: wdMock, + Prefix: "mock_prefix", + } + + d := dispatcher.New() + reporter.ConfigureWithDispatcher(d) + d.Emit(c.Topic, c.Args...) + + wdMock.AssertExpectations(t) + }) + } +} diff --git a/http/http.go b/http/http.go index 6a76daf..c1ab843 100644 --- a/http/http.go +++ b/http/http.go @@ -4,7 +4,10 @@ import ( "encoding/json" "net" "net/http" + "strings" "time" + + "github.com/gorilla/mux" ) type Emitter interface { @@ -28,6 +31,53 @@ func Serve(address string, handler http.Handler) error { return server.Serve(listener) } +type loggingResponseWriter struct { + http.ResponseWriter + statusCode int +} + +func (lrw *loggingResponseWriter) WriteHeader(code int) { + lrw.statusCode = code + lrw.ResponseWriter.WriteHeader(code) +} + +func CreateRequestEventsMiddleware(emitter Emitter, prefix string) mux.MiddlewareFunc { + beforeTopic := strings.Join([]string{prefix, "before_request"}, ":") + afterTopic := strings.Join([]string{prefix, "after_request"}, ":") + + return func(handler http.Handler) http.Handler { + return http.HandlerFunc(func(resp http.ResponseWriter, req *http.Request) { + emitter.Emit(beforeTopic, req) + + lrw := &loggingResponseWriter{ + ResponseWriter: resp, + statusCode: http.StatusOK, + } + handler.ServeHTTP(lrw, req) + + emitter.Emit(afterTopic, req, lrw.statusCode) + }) + } +} + +type Authenticator interface { + Authenticate(req *http.Request) error +} + +func CreateAuthenticationMiddleware(checker Authenticator) mux.MiddlewareFunc { + return func(handler http.Handler) http.Handler { + return http.HandlerFunc(func(resp http.ResponseWriter, req *http.Request) { + err := checker.Authenticate(req) + if err != nil { + apiForbidden(resp, err.Error()) + return + } + + handler.ServeHTTP(resp, req) + }) + } +} + func NotFound(response http.ResponseWriter, _ *http.Request) { data, _ := json.Marshal(map[string]string{ "status": "404", diff --git a/http/http_test.go b/http/http_test.go index 376f1f6..d9abfe5 100644 --- a/http/http_test.go +++ b/http/http_test.go @@ -1,7 +1,9 @@ package http import ( + "errors" "io/ioutil" + "net/http" "net/http/httptest" "testing" @@ -14,10 +16,84 @@ type emitterMock struct { } func (e *emitterMock) Emit(name string, args ...interface{}) { - e.Called((append([]interface{}{name}, args...))...) + e.Called(append([]interface{}{name}, args...)...) } -func TestConfig_NotFound(t *testing.T) { +func TestCreateRequestEventsMiddleware(t *testing.T) { + req := httptest.NewRequest("GET", "http://example.com", nil) + resp := httptest.NewRecorder() + + emitter := &emitterMock{} + emitter.On("Emit", "test_prefix:before_request", req) + emitter.On("Emit", "test_prefix:after_request", req, 400) + + isHandlerCalled := false + middlewareFunc := CreateRequestEventsMiddleware(emitter, "test_prefix") + middlewareFunc.Middleware(http.HandlerFunc(func(resp http.ResponseWriter, req *http.Request) { + resp.WriteHeader(400) + isHandlerCalled = true + })).ServeHTTP(resp, req) + + if !isHandlerCalled { + t.Fatal("Handler isn't called from the middleware") + } + + emitter.AssertExpectations(t) +} + +type authCheckerMock struct { + mock.Mock +} + +func (m *authCheckerMock) Authenticate(req *http.Request) error { + args := m.Called(req) + return args.Error(0) +} + +func TestCreateAuthenticationMiddleware(t *testing.T) { + t.Run("pass", func(t *testing.T) { + req := httptest.NewRequest("GET", "http://example.com", nil) + resp := httptest.NewRecorder() + + auth := &authCheckerMock{} + auth.On("Authenticate", req).Once().Return(nil) + + isHandlerCalled := false + middlewareFunc := CreateAuthenticationMiddleware(auth) + middlewareFunc.Middleware(http.HandlerFunc(func(resp http.ResponseWriter, req *http.Request) { + isHandlerCalled = true + })).ServeHTTP(resp, req) + + testify.True(t, isHandlerCalled, "Handler isn't called from the middleware") + + auth.AssertExpectations(t) + }) + + t.Run("fail", func(t *testing.T) { + req := httptest.NewRequest("GET", "http://example.com", nil) + resp := httptest.NewRecorder() + + auth := &authCheckerMock{} + auth.On("Authenticate", req).Once().Return(errors.New("error reason")) + + isHandlerCalled := false + middlewareFunc := CreateAuthenticationMiddleware(auth) + middlewareFunc.Middleware(http.HandlerFunc(func(resp http.ResponseWriter, req *http.Request) { + isHandlerCalled = true + })).ServeHTTP(resp, req) + + testify.False(t, isHandlerCalled, "Handler shouldn't be called") + testify.Equal(t, 403, resp.Code) + body, _ := ioutil.ReadAll(resp.Body) + testify.JSONEq(t, `{ + "error": "error reason" + }`, string(body)) + + auth.AssertExpectations(t) + }) +} + +func TestNotFound(t *testing.T) { assert := testify.New(t) req := httptest.NewRequest("GET", "http://example.com", nil) diff --git a/auth/jwt.go b/http/jwt.go similarity index 63% rename from auth/jwt.go rename to http/jwt.go index 7d86618..94f196b 100644 --- a/auth/jwt.go +++ b/http/jwt.go @@ -1,4 +1,4 @@ -package auth +package http import ( "errors" @@ -21,6 +21,7 @@ var ( ) type JwtAuth struct { + Emitter Key []byte } @@ -41,42 +42,37 @@ func (t *JwtAuth) NewToken(scopes ...Scope) ([]byte, error) { return token, nil } -func (t *JwtAuth) Check(req *http.Request) error { +func (t *JwtAuth) Authenticate(req *http.Request) error { if len(t.Key) == 0 { - return &Unauthorized{"Signing key not set"} + return t.emitErr(errors.New("Signing key not set")) } bearerToken := req.Header.Get("Authorization") if bearerToken == "" { - return &Unauthorized{"Authentication header not presented"} + return t.emitErr(errors.New("Authentication header not presented")) } if !strings.EqualFold(bearerToken[0:7], "BEARER ") { - return &Unauthorized{"Cannot recognize JWT token in passed value"} + return t.emitErr(errors.New("Cannot recognize JWT token in passed value")) } tokenStr := bearerToken[7:] token, err := jws.ParseJWT([]byte(tokenStr)) if err != nil { - return &Unauthorized{"Cannot parse passed JWT token"} + return t.emitErr(errors.New("Cannot parse passed JWT token")) } err = token.Validate(t.Key, hashAlg) if err != nil { - return &Unauthorized{"JWT token have invalid signature. It may be corrupted or expired."} + return t.emitErr(errors.New("JWT token have invalid signature. It may be corrupted or expired")) } + t.Emit("authentication:success") + return nil } -type Unauthorized struct { - Reason string -} - -func (e *Unauthorized) Error() string { - if e.Reason != "" { - return e.Reason - } - - return "Unauthorized" +func (t *JwtAuth) emitErr(err error) error { + t.Emit("authentication:error", err) + return err } diff --git a/http/jwt_test.go b/http/jwt_test.go new file mode 100644 index 0000000..92c9846 --- /dev/null +++ b/http/jwt_test.go @@ -0,0 +1,127 @@ +package http + +import ( + "net/http/httptest" + "testing" + + "github.com/stretchr/testify/assert" + "github.com/stretchr/testify/mock" +) + +const jwt = "eyJhbGciOiJIUzI1NiIsInR5cCI6IkpXVCJ9.eyJzdWIiOiIxNTE2NjU4MTkzIiwic2NvcGVzIjoic2tpbiJ9.agbBS0qdyYMBaVfTZJAZcTTRgW1Y0kZty4H3N2JHBO8" + +func TestJwtAuth_NewToken(t *testing.T) { + t.Run("success", func(t *testing.T) { + jwt := &JwtAuth{Key: []byte("secret")} + token, err := jwt.NewToken(SkinScope) + assert.Nil(t, err) + assert.NotNil(t, token) + }) + + t.Run("key not provided", func(t *testing.T) { + jwt := &JwtAuth{} + token, err := jwt.NewToken(SkinScope) + assert.Error(t, err, "signing key not available") + assert.Nil(t, token) + }) +} + +func TestJwtAuth_Authenticate(t *testing.T) { + t.Run("success", func(t *testing.T) { + emitter := &emitterMock{} + emitter.On("Emit", "authentication:success") + + req := httptest.NewRequest("POST", "http://localhost", nil) + req.Header.Add("Authorization", "Bearer " + jwt) + jwt := &JwtAuth{Key: []byte("secret"), Emitter: emitter} + + err := jwt.Authenticate(req) + assert.Nil(t, err) + + emitter.AssertExpectations(t) + }) + + t.Run("request without auth header", func(t *testing.T) { + emitter := &emitterMock{} + emitter.On("Emit", "authentication:error", mock.MatchedBy(func(err error) bool { + assert.Error(t, err, "Authentication header not presented") + return true + })) + + req := httptest.NewRequest("POST", "http://localhost", nil) + jwt := &JwtAuth{Key: []byte("secret"), Emitter: emitter} + + err := jwt.Authenticate(req) + assert.Error(t, err, "Authentication header not presented") + + emitter.AssertExpectations(t) + }) + + t.Run("no bearer token prefix", func(t *testing.T) { + emitter := &emitterMock{} + emitter.On("Emit", "authentication:error", mock.MatchedBy(func(err error) bool { + assert.Error(t, err, "Cannot recognize JWT token in passed value") + return true + })) + + req := httptest.NewRequest("POST", "http://localhost", nil) + req.Header.Add("Authorization", "this is not jwt") + jwt := &JwtAuth{Key: []byte("secret"), Emitter: emitter} + + err := jwt.Authenticate(req) + assert.Error(t, err, "Cannot recognize JWT token in passed value") + + emitter.AssertExpectations(t) + }) + + t.Run("bearer token but not jwt", func(t *testing.T) { + emitter := &emitterMock{} + emitter.On("Emit", "authentication:error", mock.MatchedBy(func(err error) bool { + assert.Error(t, err, "Cannot parse passed JWT token") + return true + })) + + req := httptest.NewRequest("POST", "http://localhost", nil) + req.Header.Add("Authorization", "Bearer thisIs.Not.Jwt") + jwt := &JwtAuth{Key: []byte("secret"), Emitter: emitter} + + err := jwt.Authenticate(req) + assert.Error(t, err, "Cannot parse passed JWT token") + + emitter.AssertExpectations(t) + }) + + t.Run("when secret is not set", func(t *testing.T) { + emitter := &emitterMock{} + emitter.On("Emit", "authentication:error", mock.MatchedBy(func(err error) bool { + assert.Error(t, err, "Signing key not set") + return true + })) + + req := httptest.NewRequest("POST", "http://localhost", nil) + req.Header.Add("Authorization", "Bearer " + jwt) + jwt := &JwtAuth{Emitter: emitter} + + err := jwt.Authenticate(req) + assert.Error(t, err, "Signing key not set") + + emitter.AssertExpectations(t) + }) + + t.Run("invalid signature", func(t *testing.T) { + emitter := &emitterMock{} + emitter.On("Emit", "authentication:error", mock.MatchedBy(func(err error) bool { + assert.Error(t, err, "JWT token have invalid signature. It may be corrupted or expired") + return true + })) + + req := httptest.NewRequest("POST", "http://localhost", nil) + req.Header.Add("Authorization", "Bearer " + jwt) + jwt := &JwtAuth{Key: []byte("this is another secret"), Emitter: emitter} + + err := jwt.Authenticate(req) + assert.Error(t, err, "JWT token have invalid signature. It may be corrupted or expired") + + emitter.AssertExpectations(t) + }) +} diff --git a/http/skinsystem.go b/http/skinsystem.go index f608276..a5c6f11 100644 --- a/http/skinsystem.go +++ b/http/skinsystem.go @@ -14,10 +14,10 @@ import ( "github.com/thedevsaddam/govalidator" "github.com/elyby/chrly/api/mojang" - "github.com/elyby/chrly/auth" "github.com/elyby/chrly/model" ) +//noinspection GoSnakeCaseUsage const UUID_ANY = "^[0-9a-f]{8}-[0-9a-f]{4}-[0-9a-f]{4}-[0-9a-f]{4}-[0-9a-f]{12}$" var regexUuidAny = regexp.MustCompile(UUID_ANY) @@ -78,10 +78,6 @@ type MojangTexturesProvider interface { GetForUsername(username string) (*mojang.SignedTexturesResponse, error) } -type AuthChecker interface { - Check(req *http.Request) error -} - type Skinsystem struct { Emitter TexturesExtraParamName string @@ -89,25 +85,26 @@ type Skinsystem struct { SkinsRepo SkinsRepository CapesRepo CapesRepository MojangTexturesProvider MojangTexturesProvider - Auth AuthChecker + Authenticator Authenticator } func (ctx *Skinsystem) CreateHandler() *mux.Router { router := mux.NewRouter().StrictSlash(true) + router.Use(CreateRequestEventsMiddleware(ctx.Emitter, "skinsystem")) - router.HandleFunc("/skins/{username}", ctx.Skin).Methods("GET") - router.HandleFunc("/cloaks/{username}", ctx.Cape).Methods("GET").Name("cloaks") - router.HandleFunc("/textures/{username}", ctx.Textures).Methods("GET") - router.HandleFunc("/textures/signed/{username}", ctx.SignedTextures).Methods("GET") + router.HandleFunc("/skins/{username}", ctx.Skin).Methods(http.MethodGet) + router.HandleFunc("/cloaks/{username}", ctx.Cape).Methods(http.MethodGet).Name("cloaks") + router.HandleFunc("/textures/{username}", ctx.Textures).Methods(http.MethodGet) + router.HandleFunc("/textures/signed/{username}", ctx.SignedTextures).Methods(http.MethodGet) // Legacy - router.HandleFunc("/skins", ctx.SkinGET).Methods("GET") - router.HandleFunc("/cloaks", ctx.CapeGET).Methods("GET") + router.HandleFunc("/skins", ctx.SkinGET).Methods(http.MethodGet) + router.HandleFunc("/cloaks", ctx.CapeGET).Methods(http.MethodGet) // API apiRouter := router.PathPrefix("/api").Subrouter() - apiRouter.Use(ctx.AuthenticationMiddleware) - apiRouter.HandleFunc("/skins", ctx.PostSkin).Methods("POST") - apiRouter.HandleFunc("/skins/id:{id:[0-9]+}", ctx.DeleteSkinByUserId).Methods("DELETE") - apiRouter.HandleFunc("/skins/{username}", ctx.DeleteSkinByUsername).Methods("DELETE") + apiRouter.Use(CreateAuthenticationMiddleware(ctx.Authenticator)) + apiRouter.HandleFunc("/skins", ctx.PostSkin).Methods(http.MethodPost) + apiRouter.HandleFunc("/skins/id:{id:[0-9]+}", ctx.DeleteSkinByUserId).Methods(http.MethodDelete) + apiRouter.HandleFunc("/skins/{username}", ctx.DeleteSkinByUsername).Methods(http.MethodDelete) // 404 router.NotFoundHandler = http.HandlerFunc(NotFound) @@ -226,7 +223,7 @@ func (ctx *Skinsystem) Textures(response http.ResponseWriter, request *http.Requ texturesProp := mojangTextures.DecodeTextures() if texturesProp == nil { - ctx.Emit("skinsystem.error", errors.New("unable to find textures property")) + ctx.Emit("skinsystem:error", errors.New("unable to find textures property")) apiServerError(response) return } @@ -330,28 +327,6 @@ func (ctx *Skinsystem) DeleteSkinByUsername(resp http.ResponseWriter, req *http. ctx.deleteSkin(skin, err, resp) } -func (ctx *Skinsystem) AuthenticationMiddleware(handler http.Handler) http.Handler { - return http.HandlerFunc(func(resp http.ResponseWriter, req *http.Request) { - // TODO: decide on how I would cover this with logging - // ctx.Logger.IncCounter("authentication.challenge", 1) - err := ctx.Auth.Check(req) - if err != nil { - if _, ok := err.(*auth.Unauthorized); ok { - // ctx.Logger.IncCounter("authentication.failed", 1) - apiForbidden(resp, err.Error()) - } else { - // ctx.Logger.Error("Unknown error on validating api request: :err", wd.ErrParam(err)) - apiServerError(resp) - } - - return - } - - // ctx.Logger.IncCounter("authentication.success", 1) - handler.ServeHTTP(resp, req) - }) -} - func (ctx *Skinsystem) deleteSkin(skin *model.Skin, err error, resp http.ResponseWriter) { if err != nil { if _, ok := err.(*SkinNotFoundError); ok { diff --git a/http/skinsystem_test.go b/http/skinsystem_test.go index 78bc29c..89f317d 100644 --- a/http/skinsystem_test.go +++ b/http/skinsystem_test.go @@ -20,7 +20,6 @@ import ( "github.com/stretchr/testify/suite" "github.com/elyby/chrly/api/mojang" - "github.com/elyby/chrly/auth" "github.com/elyby/chrly/model" ) @@ -95,15 +94,6 @@ func (m *mojangTexturesProviderMock) GetForUsername(username string) (*mojang.Si return result, args.Error(1) } -type authCheckerMock struct { - mock.Mock -} - -func (m *authCheckerMock) Check(req *http.Request) error { - args := m.Called(req) - return args.Error(0) -} - type skinsystemTestSuite struct { suite.Suite @@ -131,7 +121,7 @@ func (suite *skinsystemTestSuite) SetupTest() { SkinsRepo: suite.SkinsRepository, CapesRepo: suite.CapesRepository, MojangTexturesProvider: suite.MojangTexturesProvider, - Auth: suite.Auth, + Authenticator: suite.Auth, Emitter: suite.Emitter, } } @@ -215,6 +205,8 @@ var skinsTestsCases = []*skinsystemTestCase{ func (suite *skinsystemTestSuite) TestSkin() { for _, testCase := range skinsTestsCases { suite.RunSubTest(testCase.Name, func() { + suite.Emitter.On("Emit", "skinsystem:before_request", mock.Anything) + suite.Emitter.On("Emit", "skinsystem:after_request", mock.Anything, mock.Anything) testCase.BeforeTest(suite) req := httptest.NewRequest("GET", "http://chrly/skins/mock_username", nil) @@ -227,6 +219,8 @@ func (suite *skinsystemTestSuite) TestSkin() { } suite.RunSubTest("Pass username with png extension", func() { + suite.Emitter.On("Emit", "skinsystem:before_request", mock.Anything) + suite.Emitter.On("Emit", "skinsystem:after_request", mock.Anything, mock.Anything) suite.SkinsRepository.On("FindByUsername", "mock_username").Return(createSkinModel("mock_username", false), nil) req := httptest.NewRequest("GET", "http://chrly/skins/mock_username.png", nil) @@ -243,6 +237,8 @@ func (suite *skinsystemTestSuite) TestSkin() { func (suite *skinsystemTestSuite) TestSkinGET() { for _, testCase := range skinsTestsCases { suite.RunSubTest(testCase.Name, func() { + suite.Emitter.On("Emit", "skinsystem:before_request", mock.Anything) + suite.Emitter.On("Emit", "skinsystem:after_request", mock.Anything, mock.Anything) testCase.BeforeTest(suite) req := httptest.NewRequest("GET", "http://chrly/skins?name=mock_username", nil) @@ -255,6 +251,9 @@ func (suite *skinsystemTestSuite) TestSkinGET() { } suite.RunSubTest("Do not pass name param", func() { + suite.Emitter.On("Emit", "skinsystem:before_request", mock.Anything) + suite.Emitter.On("Emit", "skinsystem:after_request", mock.Anything, mock.Anything) + req := httptest.NewRequest("GET", "http://chrly/skins", nil) w := httptest.NewRecorder() @@ -318,6 +317,8 @@ var capesTestsCases = []*skinsystemTestCase{ func (suite *skinsystemTestSuite) TestCape() { for _, testCase := range capesTestsCases { suite.RunSubTest(testCase.Name, func() { + suite.Emitter.On("Emit", "skinsystem:before_request", mock.Anything) + suite.Emitter.On("Emit", "skinsystem:after_request", mock.Anything, mock.Anything) testCase.BeforeTest(suite) req := httptest.NewRequest("GET", "http://chrly/cloaks/mock_username", nil) @@ -330,6 +331,8 @@ func (suite *skinsystemTestSuite) TestCape() { } suite.RunSubTest("Pass username with png extension", func() { + suite.Emitter.On("Emit", "skinsystem:before_request", mock.Anything) + suite.Emitter.On("Emit", "skinsystem:after_request", mock.Anything, mock.Anything) suite.CapesRepository.On("FindByUsername", "mock_username").Return(createCapeModel(), nil) req := httptest.NewRequest("GET", "http://chrly/cloaks/mock_username.png", nil) @@ -348,6 +351,8 @@ func (suite *skinsystemTestSuite) TestCape() { func (suite *skinsystemTestSuite) TestCapeGET() { for _, testCase := range capesTestsCases { suite.RunSubTest(testCase.Name, func() { + suite.Emitter.On("Emit", "skinsystem:before_request", mock.Anything) + suite.Emitter.On("Emit", "skinsystem:after_request", mock.Anything, mock.Anything) testCase.BeforeTest(suite) req := httptest.NewRequest("GET", "http://chrly/cloaks?name=mock_username", nil) @@ -360,6 +365,9 @@ func (suite *skinsystemTestSuite) TestCapeGET() { } suite.RunSubTest("Do not pass name param", func() { + suite.Emitter.On("Emit", "skinsystem:before_request", mock.Anything) + suite.Emitter.On("Emit", "skinsystem:after_request", mock.Anything, mock.Anything) + req := httptest.NewRequest("GET", "http://chrly/cloaks", nil) w := httptest.NewRecorder() @@ -486,6 +494,8 @@ var texturesTestsCases = []*skinsystemTestCase{ func (suite *skinsystemTestSuite) TestTextures() { for _, testCase := range texturesTestsCases { suite.RunSubTest(testCase.Name, func() { + suite.Emitter.On("Emit", "skinsystem:before_request", mock.Anything) + suite.Emitter.On("Emit", "skinsystem:after_request", mock.Anything, mock.Anything) testCase.BeforeTest(suite) req := httptest.NewRequest("GET", "http://chrly/textures/mock_username", nil) @@ -609,6 +619,8 @@ var signedTexturesTestsCases = []*signedTexturesTestCase{ func (suite *skinsystemTestSuite) TestSignedTextures() { for _, testCase := range signedTexturesTestsCases { suite.RunSubTest(testCase.Name, func() { + suite.Emitter.On("Emit", "skinsystem:before_request", mock.Anything) + suite.Emitter.On("Emit", "skinsystem:after_request", mock.Anything, mock.Anything) testCase.BeforeTest(suite) var target string @@ -817,7 +829,9 @@ var postSkinTestsCases = []*postSkinTestCase{ func (suite *skinsystemTestSuite) TestPostSkin() { for _, testCase := range postSkinTestsCases { suite.RunSubTest(testCase.Name, func() { - suite.Auth.On("Check", mock.Anything).Return(nil) + suite.Emitter.On("Emit", "skinsystem:before_request", mock.Anything) + suite.Emitter.On("Emit", "skinsystem:after_request", mock.Anything, mock.Anything) + suite.Auth.On("Authenticate", mock.Anything).Return(nil) testCase.BeforeTest(suite) req := httptest.NewRequest("POST", "http://chrly/api/skins", testCase.Form) @@ -831,7 +845,9 @@ func (suite *skinsystemTestSuite) TestPostSkin() { } suite.RunSubTest("Get errors about required fields", func() { - suite.Auth.On("Check", mock.Anything).Return(nil) + suite.Emitter.On("Emit", "skinsystem:before_request", mock.Anything) + suite.Emitter.On("Emit", "skinsystem:after_request", mock.Anything, mock.Anything) + suite.Auth.On("Authenticate", mock.Anything).Return(nil) req := httptest.NewRequest("POST", "http://chrly/api/skins", bytes.NewBufferString(url.Values{ "mojangTextures": {"someBase64EncodedString"}, @@ -878,11 +894,13 @@ func (suite *skinsystemTestSuite) TestPostSkin() { }) suite.RunSubTest("Send request without authorization", func() { + suite.Emitter.On("Emit", "skinsystem:before_request", mock.Anything) + suite.Emitter.On("Emit", "skinsystem:after_request", mock.Anything, mock.Anything) req := httptest.NewRequest("POST", "http://chrly/api/skins", nil) req.Header.Add("Authorization", "Bearer invalid.jwt.token") w := httptest.NewRecorder() - suite.Auth.On("Check", mock.Anything).Return(&auth.Unauthorized{Reason: "Cannot parse passed JWT token"}) + suite.Auth.On("Authenticate", mock.Anything).Return(errors.New("Cannot parse passed JWT token")) suite.App.CreateHandler().ServeHTTP(w, req) @@ -896,7 +914,9 @@ func (suite *skinsystemTestSuite) TestPostSkin() { }) suite.RunSubTest("Upload textures with skin as file", func() { - suite.Auth.On("Check", mock.Anything).Return(nil) + suite.Emitter.On("Emit", "skinsystem:before_request", mock.Anything) + suite.Emitter.On("Emit", "skinsystem:after_request", mock.Anything, mock.Anything) + suite.Auth.On("Authenticate", mock.Anything).Return(nil) inputBody := &bytes.Buffer{} writer := multipart.NewWriter(inputBody) @@ -940,7 +960,9 @@ func (suite *skinsystemTestSuite) TestPostSkin() { func (suite *skinsystemTestSuite) TestDeleteByUserId() { suite.RunSubTest("Delete skin by its identity id", func() { - suite.Auth.On("Check", mock.Anything).Return(nil) + suite.Emitter.On("Emit", "skinsystem:before_request", mock.Anything) + suite.Emitter.On("Emit", "skinsystem:after_request", mock.Anything, mock.Anything) + suite.Auth.On("Authenticate", mock.Anything).Return(nil) suite.SkinsRepository.On("FindByUserId", 1).Return(createSkinModel("mock_username", false), nil) suite.SkinsRepository.On("RemoveByUserId", 1).Once().Return(nil) @@ -957,7 +979,9 @@ func (suite *skinsystemTestSuite) TestDeleteByUserId() { }) suite.RunSubTest("Try to remove not exists identity id", func() { - suite.Auth.On("Check", mock.Anything).Return(nil) + suite.Emitter.On("Emit", "skinsystem:before_request", mock.Anything) + suite.Emitter.On("Emit", "skinsystem:after_request", mock.Anything, mock.Anything) + suite.Auth.On("Authenticate", mock.Anything).Return(nil) suite.SkinsRepository.On("FindByUserId", 1).Return(nil, &SkinNotFoundError{Who: "unknown"}) req := httptest.NewRequest("DELETE", "http://chrly/api/skins/id:1", nil) @@ -981,7 +1005,9 @@ func (suite *skinsystemTestSuite) TestDeleteByUserId() { func (suite *skinsystemTestSuite) TestDeleteByUsername() { suite.RunSubTest("Delete skin by its identity username", func() { - suite.Auth.On("Check", mock.Anything).Return(nil) + suite.Emitter.On("Emit", "skinsystem:before_request", mock.Anything) + suite.Emitter.On("Emit", "skinsystem:after_request", mock.Anything, mock.Anything) + suite.Auth.On("Authenticate", mock.Anything).Return(nil) suite.SkinsRepository.On("FindByUsername", "mock_username").Return(createSkinModel("mock_username", false), nil) suite.SkinsRepository.On("RemoveByUserId", 1).Once().Return(nil) @@ -998,7 +1024,9 @@ func (suite *skinsystemTestSuite) TestDeleteByUsername() { }) suite.RunSubTest("Try to remove not exists identity username", func() { - suite.Auth.On("Check", mock.Anything).Return(nil) + suite.Emitter.On("Emit", "skinsystem:before_request", mock.Anything) + suite.Emitter.On("Emit", "skinsystem:after_request", mock.Anything, mock.Anything) + suite.Auth.On("Authenticate", mock.Anything).Return(nil) suite.SkinsRepository.On("FindByUsername", "mock_username").Return(nil, &SkinNotFoundError{Who: "mock_username"}) req := httptest.NewRequest("DELETE", "http://chrly/api/skins/mock_username", nil) From e1c30a0ba12ba14feafdf1990aedac45bc22b9ba Mon Sep 17 00:00:00 2001 From: ErickSkrauch Date: Sun, 29 Mar 2020 17:17:11 +0300 Subject: [PATCH 05/18] Generalize mojang textures events --- mojangtextures/mojang_textures.go | 64 +++++++----- mojangtextures/mojang_textures_test.go | 138 +++++++++++++++---------- 2 files changed, 123 insertions(+), 79 deletions(-) diff --git a/mojangtextures/mojang_textures.go b/mojangtextures/mojang_textures.go index b41dbe8..b04dd43 100644 --- a/mojangtextures/mojang_textures.go +++ b/mojangtextures/mojang_textures.go @@ -85,8 +85,6 @@ type Provider struct { *broadcaster } -// TODO: move cache events on the corresponding level - func (ctx *Provider) GetForUsername(username string) (*mojang.SignedTexturesResponse, error) { ctx.onFirstCall.Do(func() { ctx.broadcaster = createBroadcaster() @@ -97,19 +95,16 @@ func (ctx *Provider) GetForUsername(username string) (*mojang.SignedTexturesResp } username = strings.ToLower(username) - ctx.Emit("mojang_textures:call") + ctx.Emit("mojang_textures:call", username) - uuid, err := ctx.Storage.GetUuid(username) + uuid, err := ctx.getUuidFromCache(username) if err == nil && uuid == "" { - ctx.Emit("mojang_textures:usernames:cache_hit_nil") return nil, nil } if uuid != "" { - ctx.Emit("mojang_textures:usernames:cache_hit") - textures, err := ctx.Storage.GetTextures(uuid) + textures, err := ctx.getTexturesFromCache(uuid) if err == nil { - ctx.Emit("mojang_textures:textures:cache_hit") return textures, nil } } @@ -119,7 +114,7 @@ func (ctx *Provider) GetForUsername(username string) (*mojang.SignedTexturesResp if isFirstListener { go ctx.getResultAndBroadcast(username, uuid) } else { - ctx.Emit("mojang_textures:already_processing") + ctx.Emit("mojang_textures:already_processing", username) } result := <-resultChan @@ -128,19 +123,18 @@ func (ctx *Provider) GetForUsername(username string) (*mojang.SignedTexturesResp } func (ctx *Provider) getResultAndBroadcast(username string, uuid string) { - ctx.Emit("mojang_textures:before_get_result") + ctx.Emit("mojang_textures:before_result", username, uuid) result := ctx.getResult(username, uuid) ctx.broadcaster.BroadcastAndRemove(username, result) - ctx.Emit("mojang_textures:after_get_result") + ctx.Emit("mojang_textures:after_result", username, result.textures, result.error) } func (ctx *Provider) getResult(username string, uuid string) *broadcastResult { if uuid == "" { - profile, err := ctx.UUIDsProvider.GetUuid(username) + profile, err := ctx.getUuid(username) if err != nil { - ctx.Emit("mojang_textures:usernames:error", err) return &broadcastResult{nil, err} } @@ -152,16 +146,12 @@ func (ctx *Provider) getResult(username string, uuid string) *broadcastResult { _ = ctx.Storage.StoreUuid(username, uuid) if uuid == "" { - ctx.Emit("mojang_textures:usernames:uuid_miss") return &broadcastResult{nil, nil} } - - ctx.Emit("mojang_textures:usernames:uuid_hit") } - textures, err := ctx.TexturesProvider.GetTextures(uuid) + textures, err := ctx.getTextures(uuid) if err != nil { - ctx.Emit("mojang_textures:textures:error", err) return &broadcastResult{nil, err} } @@ -169,11 +159,37 @@ func (ctx *Provider) getResult(username string, uuid string) *broadcastResult { // therefore store the result even if textures is nil to prevent 429 error ctx.Storage.StoreTextures(uuid, textures) - if textures != nil { - ctx.Emit("mojang_textures:textures:hit") - } else { - ctx.Emit("mojang_textures:textures:miss") - } - return &broadcastResult{textures, nil} } + +func (ctx *Provider) getUuidFromCache(username string) (string, error) { + ctx.Emit("mojang_textures:usernames:before_cache", username) + uuid, err := ctx.Storage.GetUuid(username) + ctx.Emit("mojang_textures:usernames:after_cache", username, uuid, err) + + return uuid, err +} + +func (ctx *Provider) getTexturesFromCache(uuid string) (*mojang.SignedTexturesResponse, error) { + ctx.Emit("mojang_textures:textures:before_cache", uuid) + textures, err := ctx.Storage.GetTextures(uuid) + ctx.Emit("mojang_textures:textures:after_cache", uuid, textures, err) + + return textures, err +} + +func (ctx *Provider) getUuid(username string) (*mojang.ProfileInfo, error) { + ctx.Emit("mojang_textures:usernames:before_call", username) + profile, err := ctx.UUIDsProvider.GetUuid(username) + ctx.Emit("mojang_textures:usernames:after_call", username, profile, err) + + return profile, err +} + +func (ctx *Provider) getTextures(uuid string) (*mojang.SignedTexturesResponse, error) { + ctx.Emit("mojang_textures:textures:before_call", uuid) + textures, err := ctx.TexturesProvider.GetTextures(uuid) + ctx.Emit("mojang_textures:textures:after_call", uuid, textures, err) + + return textures, err +} diff --git a/mojangtextures/mojang_textures_test.go b/mojangtextures/mojang_textures_test.go index a9aef44..b5dca95 100644 --- a/mojangtextures/mojang_textures_test.go +++ b/mojangtextures/mojang_textures_test.go @@ -181,22 +181,24 @@ func TestProvider(t *testing.T) { } func (suite *providerTestSuite) TestGetForUsernameWithoutAnyCache() { + expectedProfile := &mojang.ProfileInfo{Id: "aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa", Name: "username"} expectedResult := &mojang.SignedTexturesResponse{Id: "aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa", Name: "username"} - suite.Emitter.On("Emit", "mojang_textures:call").Once() - suite.Emitter.On("Emit", "mojang_textures:before_get_result").Once() - suite.Emitter.On("Emit", "mojang_textures:usernames:uuid_hit").Once() - suite.Emitter.On("Emit", "mojang_textures:textures:hit").Once() - suite.Emitter.On("Emit", "mojang_textures:after_get_result").Once() + suite.Emitter.On("Emit", "mojang_textures:call", "username").Once() + suite.Emitter.On("Emit", "mojang_textures:usernames:before_cache", "username").Once() + suite.Emitter.On("Emit", "mojang_textures:usernames:after_cache", "username", "", &ValueNotFound{}).Once() + suite.Emitter.On("Emit", "mojang_textures:before_result", "username", "").Once() + suite.Emitter.On("Emit", "mojang_textures:usernames:before_call", "username").Once() + suite.Emitter.On("Emit", "mojang_textures:usernames:after_call", "username", expectedProfile, nil).Once() + suite.Emitter.On("Emit", "mojang_textures:textures:before_call", "aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa").Once() + suite.Emitter.On("Emit", "mojang_textures:textures:after_call", "aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa", expectedResult, nil).Once() + suite.Emitter.On("Emit", "mojang_textures:after_result", "username", expectedResult, nil).Once() suite.Storage.On("GetUuid", "username").Once().Return("", &ValueNotFound{}) suite.Storage.On("StoreUuid", "username", "aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa").Once().Return(nil) suite.Storage.On("StoreTextures", "aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa", expectedResult).Once() - suite.UuidsProvider.On("GetUuid", "username").Once().Return(&mojang.ProfileInfo{ - Id: "aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa", - Name: "username", - }, nil) + suite.UuidsProvider.On("GetUuid", "username").Once().Return(expectedProfile, nil) suite.TexturesProvider.On("GetTextures", "aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa").Once().Return(expectedResult, nil) result, err := suite.Provider.GetForUsername("username") @@ -206,13 +208,18 @@ func (suite *providerTestSuite) TestGetForUsernameWithoutAnyCache() { } func (suite *providerTestSuite) TestGetForUsernameWithCachedUuid() { + var expectedCachedTextures *mojang.SignedTexturesResponse expectedResult := &mojang.SignedTexturesResponse{Id: "aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa", Name: "username"} - suite.Emitter.On("Emit", "mojang_textures:call").Once() - suite.Emitter.On("Emit", "mojang_textures:usernames:cache_hit").Once() - suite.Emitter.On("Emit", "mojang_textures:before_get_result").Once() - suite.Emitter.On("Emit", "mojang_textures:textures:hit").Once() - suite.Emitter.On("Emit", "mojang_textures:after_get_result").Once() + suite.Emitter.On("Emit", "mojang_textures:call", "username").Once() + suite.Emitter.On("Emit", "mojang_textures:usernames:before_cache", "username").Once() + suite.Emitter.On("Emit", "mojang_textures:usernames:after_cache", "username", "aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa", nil).Once() + suite.Emitter.On("Emit", "mojang_textures:textures:before_cache", "aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa").Once() + suite.Emitter.On("Emit", "mojang_textures:textures:after_cache", "aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa", expectedCachedTextures, &ValueNotFound{}).Once() + suite.Emitter.On("Emit", "mojang_textures:before_result", "username", "aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa").Once() + suite.Emitter.On("Emit", "mojang_textures:textures:before_call", "aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa").Once() + suite.Emitter.On("Emit", "mojang_textures:textures:after_call", "aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa", expectedResult, nil).Once() + suite.Emitter.On("Emit", "mojang_textures:after_result", "username", expectedResult, nil).Once() suite.Storage.On("GetUuid", "username").Once().Return("aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa", nil) suite.Storage.On("GetTextures", "aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa").Once().Return(nil, &ValueNotFound{}) @@ -229,9 +236,11 @@ func (suite *providerTestSuite) TestGetForUsernameWithCachedUuid() { func (suite *providerTestSuite) TestGetForUsernameWithFullyCachedResult() { expectedResult := &mojang.SignedTexturesResponse{Id: "aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa", Name: "username"} - suite.Emitter.On("Emit", "mojang_textures:call").Once() - suite.Emitter.On("Emit", "mojang_textures:usernames:cache_hit").Once() - suite.Emitter.On("Emit", "mojang_textures:textures:cache_hit").Once() + suite.Emitter.On("Emit", "mojang_textures:call", "username").Once() + suite.Emitter.On("Emit", "mojang_textures:usernames:before_cache", "username").Once() + suite.Emitter.On("Emit", "mojang_textures:usernames:after_cache", "username", "aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa", nil).Once() + suite.Emitter.On("Emit", "mojang_textures:textures:before_cache", "aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa").Once() + suite.Emitter.On("Emit", "mojang_textures:textures:after_cache", "aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa", expectedResult, nil).Once() suite.Storage.On("GetUuid", "username").Once().Return("aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa", nil) suite.Storage.On("GetTextures", "aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa").Once().Return(expectedResult, nil) @@ -243,8 +252,9 @@ func (suite *providerTestSuite) TestGetForUsernameWithFullyCachedResult() { } func (suite *providerTestSuite) TestGetForUsernameWithCachedUnknownUuid() { - suite.Emitter.On("Emit", "mojang_textures:call").Once() - suite.Emitter.On("Emit", "mojang_textures:usernames:cache_hit_nil").Once() + suite.Emitter.On("Emit", "mojang_textures:call", "username").Once() + suite.Emitter.On("Emit", "mojang_textures:usernames:before_cache", "username").Once() + suite.Emitter.On("Emit", "mojang_textures:usernames:after_cache", "username", "", nil).Once() suite.Storage.On("GetUuid", "username").Once().Return("", nil) @@ -255,10 +265,16 @@ func (suite *providerTestSuite) TestGetForUsernameWithCachedUnknownUuid() { } func (suite *providerTestSuite) TestGetForUsernameWhichHasNoMojangAccount() { - suite.Emitter.On("Emit", "mojang_textures:call").Once() - suite.Emitter.On("Emit", "mojang_textures:before_get_result").Once() - suite.Emitter.On("Emit", "mojang_textures:usernames:uuid_miss").Once() - suite.Emitter.On("Emit", "mojang_textures:after_get_result").Once() + var expectedProfile *mojang.ProfileInfo + var expectedResult *mojang.SignedTexturesResponse + + suite.Emitter.On("Emit", "mojang_textures:call", "username").Once() + suite.Emitter.On("Emit", "mojang_textures:usernames:before_cache", "username").Once() + suite.Emitter.On("Emit", "mojang_textures:usernames:after_cache", "username", "", &ValueNotFound{}).Once() + suite.Emitter.On("Emit", "mojang_textures:before_result", "username", "").Once() + suite.Emitter.On("Emit", "mojang_textures:usernames:before_call", "username").Once() + suite.Emitter.On("Emit", "mojang_textures:usernames:after_call", "username", expectedProfile, nil).Once() + suite.Emitter.On("Emit", "mojang_textures:after_result", "username", expectedResult, nil).Once() suite.Storage.On("GetUuid", "username").Once().Return("", &ValueNotFound{}) suite.Storage.On("StoreUuid", "username", "").Once().Return(nil) @@ -272,22 +288,24 @@ func (suite *providerTestSuite) TestGetForUsernameWhichHasNoMojangAccount() { } func (suite *providerTestSuite) TestGetForUsernameWhichHasMojangAccountButHasNoMojangSkin() { + expectedProfile := &mojang.ProfileInfo{Id: "aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa", Name: "username"} var expectedResult *mojang.SignedTexturesResponse - suite.Emitter.On("Emit", "mojang_textures:call").Once() - suite.Emitter.On("Emit", "mojang_textures:before_get_result").Once() - suite.Emitter.On("Emit", "mojang_textures:usernames:uuid_hit").Once() - suite.Emitter.On("Emit", "mojang_textures:textures:miss").Once() - suite.Emitter.On("Emit", "mojang_textures:after_get_result").Once() + suite.Emitter.On("Emit", "mojang_textures:call", "username").Once() + suite.Emitter.On("Emit", "mojang_textures:usernames:before_cache", "username").Once() + suite.Emitter.On("Emit", "mojang_textures:usernames:after_cache", "username", "", &ValueNotFound{}).Once() + suite.Emitter.On("Emit", "mojang_textures:before_result", "username", "").Once() + suite.Emitter.On("Emit", "mojang_textures:usernames:before_call", "username").Once() + suite.Emitter.On("Emit", "mojang_textures:usernames:after_call", "username", expectedProfile, nil).Once() + suite.Emitter.On("Emit", "mojang_textures:textures:before_call", "aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa").Once() + suite.Emitter.On("Emit", "mojang_textures:textures:after_call", "aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa", expectedResult, nil).Once() + suite.Emitter.On("Emit", "mojang_textures:after_result", "username", expectedResult, nil).Once() suite.Storage.On("GetUuid", "username").Once().Return("", &ValueNotFound{}) suite.Storage.On("StoreUuid", "username", "aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa").Once().Return(nil) suite.Storage.On("StoreTextures", "aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa", expectedResult).Once() - suite.UuidsProvider.On("GetUuid", "username").Once().Return(&mojang.ProfileInfo{ - Id: "aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa", - Name: "username", - }, nil) + suite.UuidsProvider.On("GetUuid", "username").Once().Return(expectedProfile, nil) suite.TexturesProvider.On("GetTextures", "aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa").Once().Return(expectedResult, nil) result, err := suite.Provider.GetForUsername("username") @@ -297,24 +315,26 @@ func (suite *providerTestSuite) TestGetForUsernameWhichHasMojangAccountButHasNoM } func (suite *providerTestSuite) TestGetForTheSameUsernames() { + expectedProfile := &mojang.ProfileInfo{Id: "aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa", Name: "username"} expectedResult := &mojang.SignedTexturesResponse{Id: "aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa", Name: "username"} - suite.Emitter.On("Emit", "mojang_textures:call").Twice() - suite.Emitter.On("Emit", "mojang_textures:already_processing").Once() - suite.Emitter.On("Emit", "mojang_textures:before_get_result").Once() - suite.Emitter.On("Emit", "mojang_textures:usernames:uuid_hit").Once() - suite.Emitter.On("Emit", "mojang_textures:textures:hit").Once() - suite.Emitter.On("Emit", "mojang_textures:after_get_result").Once() + suite.Emitter.On("Emit", "mojang_textures:call", "username").Twice() + suite.Emitter.On("Emit", "mojang_textures:usernames:before_cache", "username").Twice() + suite.Emitter.On("Emit", "mojang_textures:usernames:after_cache", "username", "", &ValueNotFound{}).Twice() + suite.Emitter.On("Emit", "mojang_textures:already_processing", "username").Once() + suite.Emitter.On("Emit", "mojang_textures:before_result", "username", "").Once() + suite.Emitter.On("Emit", "mojang_textures:usernames:before_call", "username").Once() + suite.Emitter.On("Emit", "mojang_textures:usernames:after_call", "username", expectedProfile, nil).Once() + suite.Emitter.On("Emit", "mojang_textures:textures:before_call", "aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa").Once() + suite.Emitter.On("Emit", "mojang_textures:textures:after_call", "aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa", expectedResult, nil).Once() + suite.Emitter.On("Emit", "mojang_textures:after_result", "username", expectedResult, nil).Once() suite.Storage.On("GetUuid", "username").Twice().Return("", &ValueNotFound{}) suite.Storage.On("StoreUuid", "username", "aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa").Once().Return(nil) suite.Storage.On("StoreTextures", "aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa", expectedResult).Once() // If possible, than remove this .After call - suite.UuidsProvider.On("GetUuid", "username").Once().After(time.Millisecond).Return(&mojang.ProfileInfo{ - Id: "aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa", - Name: "username", - }, nil) + suite.UuidsProvider.On("GetUuid", "username").Once().After(time.Millisecond).Return(expectedProfile, nil) suite.TexturesProvider.On("GetTextures", "aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa").Once().Return(expectedResult, nil) results := make([]*mojang.SignedTexturesResponse, 2) @@ -340,12 +360,17 @@ func (suite *providerTestSuite) TestGetForNotAllowedMojangUsername() { } func (suite *providerTestSuite) TestGetErrorFromUuidsProvider() { + var expectedProfile *mojang.ProfileInfo + var expectedResult *mojang.SignedTexturesResponse err := errors.New("mock error") - suite.Emitter.On("Emit", "mojang_textures:call").Once() - suite.Emitter.On("Emit", "mojang_textures:before_get_result").Once() - suite.Emitter.On("Emit", "mojang_textures:usernames:error", err).Once() - suite.Emitter.On("Emit", "mojang_textures:after_get_result").Once() + suite.Emitter.On("Emit", "mojang_textures:call", "username").Once() + suite.Emitter.On("Emit", "mojang_textures:usernames:before_cache", "username").Once() + suite.Emitter.On("Emit", "mojang_textures:usernames:after_cache", "username", "", &ValueNotFound{}).Once() + suite.Emitter.On("Emit", "mojang_textures:before_result", "username", "").Once() + suite.Emitter.On("Emit", "mojang_textures:usernames:before_call", "username").Once() + suite.Emitter.On("Emit", "mojang_textures:usernames:after_call", "username", expectedProfile, err).Once() + suite.Emitter.On("Emit", "mojang_textures:after_result", "username", expectedResult, err).Once() suite.Storage.On("GetUuid", "username").Once().Return("", &ValueNotFound{}) suite.UuidsProvider.On("GetUuid", "username").Once().Return(nil, err) @@ -356,20 +381,23 @@ func (suite *providerTestSuite) TestGetErrorFromUuidsProvider() { } func (suite *providerTestSuite) TestGetErrorFromTexturesProvider() { + expectedProfile := &mojang.ProfileInfo{Id: "aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa", Name: "username"} + var expectedResult *mojang.SignedTexturesResponse err := errors.New("mock error") - suite.Emitter.On("Emit", "mojang_textures:call").Once() - suite.Emitter.On("Emit", "mojang_textures:before_get_result").Once() - suite.Emitter.On("Emit", "mojang_textures:usernames:uuid_hit").Once() - suite.Emitter.On("Emit", "mojang_textures:textures:error", err).Once() - suite.Emitter.On("Emit", "mojang_textures:after_get_result").Once() + suite.Emitter.On("Emit", "mojang_textures:call", "username").Once() + suite.Emitter.On("Emit", "mojang_textures:usernames:before_cache", "username").Once() + suite.Emitter.On("Emit", "mojang_textures:usernames:after_cache", "username", "", &ValueNotFound{}).Once() + suite.Emitter.On("Emit", "mojang_textures:before_result", "username", "").Once() + suite.Emitter.On("Emit", "mojang_textures:usernames:before_call", "username").Once() + suite.Emitter.On("Emit", "mojang_textures:usernames:after_call", "username", expectedProfile, nil).Once() + suite.Emitter.On("Emit", "mojang_textures:textures:before_call", "aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa").Once() + suite.Emitter.On("Emit", "mojang_textures:textures:after_call", "aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa", expectedResult, err).Once() + suite.Emitter.On("Emit", "mojang_textures:after_result", "username", expectedResult, err).Once() suite.Storage.On("GetUuid", "username").Return("", &ValueNotFound{}) suite.Storage.On("StoreUuid", "username", "aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa").Return(nil) - suite.UuidsProvider.On("GetUuid", "username").Once().Return(&mojang.ProfileInfo{ - Id: "aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa", - Name: "username", - }, nil) + suite.UuidsProvider.On("GetUuid", "username").Once().Return(expectedProfile, nil) suite.TexturesProvider.On("GetTextures", "aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa").Once().Return(nil, err) result, resErr := suite.Provider.GetForUsername("username") From e3b9e3c069216b461a09d01f9fb93c35fb97fe82 Mon Sep 17 00:00:00 2001 From: ErickSkrauch Date: Mon, 30 Mar 2020 12:30:06 +0300 Subject: [PATCH 06/18] Add events handlers to reimplement all statsd metrics, available before refactoring. Tests aren't working at this time :( Removed mojang_textures.invalid_username metric. --- CHANGELOG.md | 3 + eventsubscribers/stats_reporter.go | 105 +++++++++++++++ eventsubscribers/stats_reporter_test.go | 171 ++++++++++++++++++------ 3 files changed, 236 insertions(+), 43 deletions(-) diff --git a/CHANGELOG.md b/CHANGELOG.md index 752e1c3..a03a99d 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -34,6 +34,9 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0 - **BREAKING**: Event `ely.skinsystem.{hostname}.app.mojang_textures.already_in_queue` has been renamed into `ely.skinsystem.{hostname}.app.mojang_textures.already_scheduled`. +### Removed +- **BREAKING**: `ely.skinsystem.{hostname}.app.mojang_textures.invalid_username` counter has been removed. + ## [4.3.0] - 2019-11-08 ### Added - 403 Forbidden errors from the Mojang's API are now logged. diff --git a/eventsubscribers/stats_reporter.go b/eventsubscribers/stats_reporter.go index ad0e449..2a1ce2b 100644 --- a/eventsubscribers/stats_reporter.go +++ b/eventsubscribers/stats_reporter.go @@ -3,25 +3,104 @@ package eventsubscribers import ( "net/http" "strings" + "sync" + "time" "github.com/mono83/slf" + "github.com/elyby/chrly/api/mojang" "github.com/elyby/chrly/dispatcher" ) type StatsReporter struct { Reporter slf.StatsReporter Prefix string + + timersMap sync.Map } func (s *StatsReporter) ConfigureWithDispatcher(d dispatcher.EventDispatcher) { + // Per request events d.Subscribe("skinsystem:before_request", s.handleBeforeRequest) d.Subscribe("skinsystem:after_request", s.handleAfterRequest) + // Authentication events d.Subscribe("authenticator:success", s.incCounterHandler("authentication.challenge")) // TODO: legacy, remove in v5 d.Subscribe("authenticator:success", s.incCounterHandler("authentication.success")) d.Subscribe("authentication:error", s.incCounterHandler("authentication.challenge")) // TODO: legacy, remove in v5 d.Subscribe("authentication:error", s.incCounterHandler("authentication.failed")) + + // Mojang signed textures source events + d.Subscribe("mojang_textures:call", s.incCounterHandler("mojang_textures.request")) + d.Subscribe("mojang_textures:usernames:after_cache", func(username string, uuid string, err error) { + if err != nil { + return + } + + if uuid == "" { + s.incCounter("mojang_textures:usernames:cache_hit_nil") + } else { + s.incCounter("mojang_textures:usernames:cache_hit") + } + }) + d.Subscribe("mojang_textures:textures:after_cache", func(uuid string, textures *mojang.SignedTexturesResponse, err error) { + if err != nil { + return + } + + if textures != nil { + s.incCounter("mojang_textures.textures.cache_hit") + } + }) + d.Subscribe("mojang_textures:already_processing", s.incCounterHandler("mojang_textures.already_scheduled")) + d.Subscribe("mojang_textures:usernames:after_call", func(username string, profile *mojang.ProfileInfo, err error) { + if err != nil { + return + } + + if profile == nil { + s.incCounter("mojang_textures.usernames.uuid_miss") + } else { + s.incCounter("mojang_textures.usernames.uuid_hit") + } + }) + d.Subscribe("mojang_textures:textures:before_call", s.incCounterHandler("mojang_textures.textures.request")) + d.Subscribe("mojang_textures:textures:after_call", func(uuid string, textures *mojang.SignedTexturesResponse, err error) { + if err != nil { + return + } + + if textures == nil { + s.incCounter("mojang_textures.usernames.textures_miss") + } else { + s.incCounter("mojang_textures.usernames.textures_hit") + } + }) + d.Subscribe("mojang_textures:before_result", func(username string, uuid string) { + s.startTimeRecording("mojang_textures_result_time_" + username) + }) + d.Subscribe("mojang_textures:after_result", func(username string, textures *mojang.SignedTexturesResponse, err error) { + s.finalizeTimeRecording("mojang_textures_result_time_"+username, "mojang_textures.result_time") + }) + d.Subscribe("mojang_textures:textures:before_call", func(uuid string) { + s.startTimeRecording("mojang_textures_provider_time_" + uuid) + }) + d.Subscribe("mojang_textures:textures:after_call", func(uuid string, textures *mojang.SignedTexturesResponse, err error) { + s.finalizeTimeRecording("mojang_textures_provider_time_"+uuid, "mojang_textures.textures.request_time") + }) + + // Mojang UUIDs batch provider metrics + d.Subscribe("mojang_textures:batch_uuids_provider:queued", s.incCounterHandler("mojang_textures.usernames.queued")) + d.Subscribe("mojang_textures:batch_uuids_provider:round", func(usernames []string, queueSize int) { + s.updateGauge("mojang_textures.usernames.iteration_size", int64(len(usernames))) + s.updateGauge("mojang_textures.usernames.queue_size", int64(queueSize)) + }) + d.Subscribe("mojang_textures:batch_uuids_provider:before_round", func() { + s.startTimeRecording("batch_uuids_provider_round_time") + }) + d.Subscribe("mojang_textures:batch_uuids_provider:after_round", func() { + s.finalizeTimeRecording("batch_uuids_provider_round_time", "mojang_textures.usernames.round_time") + }) } func (s *StatsReporter) handleBeforeRequest(req *http.Request) { @@ -76,10 +155,36 @@ func (s *StatsReporter) incCounterHandler(name string) func(...interface{}) { } } +func (s *StatsReporter) startTimeRecording(timeKey string) { + s.timersMap.Store(timeKey, time.Now()) +} + +func (s *StatsReporter) finalizeTimeRecording(timeKey string, statName string) { + startedAtUncasted, ok := s.timersMap.Load(timeKey) + if !ok { + return + } + + startedAt, ok := startedAtUncasted.(time.Time) + if !ok { + panic("unable to cast map value to the time.Time") + } + + s.recordTimer(statName, time.Since(startedAt)) +} + func (s *StatsReporter) incCounter(name string) { s.Reporter.IncCounter(s.key(name), 1) } +func (s *StatsReporter) updateGauge(name string, value int64) { + s.Reporter.UpdateGauge(s.key(name), value) +} + +func (s *StatsReporter) recordTimer(name string, duration time.Duration) { + s.Reporter.RecordTimer(s.key(name), duration) +} + func (s *StatsReporter) key(name string) string { return strings.Join([]string{s.Prefix, name}, ".") } diff --git a/eventsubscribers/stats_reporter_test.go b/eventsubscribers/stats_reporter_test.go index 7d0ea24..fc7e74b 100644 --- a/eventsubscribers/stats_reporter_test.go +++ b/eventsubscribers/stats_reporter_test.go @@ -5,156 +5,239 @@ import ( "net/http/httptest" "testing" + "github.com/stretchr/testify/mock" + + "github.com/elyby/chrly/api/mojang" "github.com/elyby/chrly/dispatcher" "github.com/elyby/chrly/tests" ) type StatsReporterTestCase struct { - Topic string - Args []interface{} + Events map[string][]interface{} ExpectedCalls [][]interface{} } +type NilErr struct { +} + +func (n *NilErr) Error() string { + panic("don't call me") +} + +// This let me to test events with nil error arguments. +// I can't just use `var nilErr error = nil`, because when Golang calls reflect.ValueOf() +// its returns only nil, without type. But when he calls reflection on specific structure (or pointer in this case), +// everything works fine. This is a memorial of 2 hours of my life, debugging and learning from the reflection +// about Go's types system. Nothing to regret. +var nilErr *NilErr = nil + var statsReporterTestCases = []*StatsReporterTestCase{ // Before request { - Topic: "skinsystem:before_request", - Args: []interface{}{httptest.NewRequest("GET", "http://localhost/skins/username", nil)}, + Events: map[string][]interface{}{ + "skinsystem:before_request": {httptest.NewRequest("GET", "http://localhost/skins/username", nil)}, + }, ExpectedCalls: [][]interface{}{ {"IncCounter", "mock_prefix.skins.request", int64(1)}, }, }, { - Topic: "skinsystem:before_request", - Args: []interface{}{httptest.NewRequest("GET", "http://localhost/skins?name=username", nil)}, + Events: map[string][]interface{}{ + "skinsystem:before_request": {httptest.NewRequest("GET", "http://localhost/skins?name=username", nil)}, + }, ExpectedCalls: [][]interface{}{ {"IncCounter", "mock_prefix.skins.get_request", int64(1)}, }, }, { - Topic: "skinsystem:before_request", - Args: []interface{}{httptest.NewRequest("GET", "http://localhost/cloaks/username", nil)}, + Events: map[string][]interface{}{ + "skinsystem:before_request": {httptest.NewRequest("GET", "http://localhost/cloaks/username", nil)}, + }, ExpectedCalls: [][]interface{}{ {"IncCounter", "mock_prefix.capes.request", int64(1)}, }, }, { - Topic: "skinsystem:before_request", - Args: []interface{}{httptest.NewRequest("GET", "http://localhost/cloaks?name=username", nil)}, + Events: map[string][]interface{}{ + "skinsystem:before_request": {httptest.NewRequest("GET", "http://localhost/cloaks?name=username", nil)}, + }, ExpectedCalls: [][]interface{}{ {"IncCounter", "mock_prefix.capes.get_request", int64(1)}, }, }, { - Topic: "skinsystem:before_request", - Args: []interface{}{httptest.NewRequest("GET", "http://localhost/textures/username", nil)}, + Events: map[string][]interface{}{ + "skinsystem:before_request": {httptest.NewRequest("GET", "http://localhost/textures/username", nil)}, + }, ExpectedCalls: [][]interface{}{ {"IncCounter", "mock_prefix.textures.request", int64(1)}, }, }, { - Topic: "skinsystem:before_request", - Args: []interface{}{httptest.NewRequest("GET", "http://localhost/textures/signed/username", nil)}, + Events: map[string][]interface{}{ + "skinsystem:before_request": {httptest.NewRequest("GET", "http://localhost/textures/signed/username", nil)}, + }, ExpectedCalls: [][]interface{}{ {"IncCounter", "mock_prefix.signed_textures.request", int64(1)}, }, }, { - Topic: "skinsystem:before_request", - Args: []interface{}{httptest.NewRequest("POST", "http://localhost/api/skins", nil)}, + Events: map[string][]interface{}{ + "skinsystem:before_request": {httptest.NewRequest("POST", "http://localhost/api/skins", nil)}, + }, ExpectedCalls: [][]interface{}{ {"IncCounter", "mock_prefix.api.skins.post.request", int64(1)}, }, }, { - Topic: "skinsystem:before_request", - Args: []interface{}{httptest.NewRequest("DELETE", "http://localhost/api/skins/username", nil)}, + Events: map[string][]interface{}{ + "skinsystem:before_request": {httptest.NewRequest("DELETE", "http://localhost/api/skins/username", nil)}, + }, ExpectedCalls: [][]interface{}{ {"IncCounter", "mock_prefix.api.skins.delete.request", int64(1)}, }, }, { - Topic: "skinsystem:before_request", - Args: []interface{}{httptest.NewRequest("DELETE", "http://localhost/api/skins/id:1", nil)}, + Events: map[string][]interface{}{ + "skinsystem:before_request": {httptest.NewRequest("DELETE", "http://localhost/api/skins/id:1", nil)}, + }, ExpectedCalls: [][]interface{}{ {"IncCounter", "mock_prefix.api.skins.delete.request", int64(1)}, }, }, { - Topic: "skinsystem:before_request", - Args: []interface{}{httptest.NewRequest("GET", "http://localhost/unknown", nil)}, + Events: map[string][]interface{}{ + "skinsystem:before_request": {httptest.NewRequest("GET", "http://localhost/unknown", nil)}, + }, ExpectedCalls: nil, }, // After request { - Topic: "skinsystem:after_request", - Args: []interface{}{httptest.NewRequest("POST", "http://localhost/api/skins", nil), 201}, + Events: map[string][]interface{}{ + "skinsystem:after_request": {httptest.NewRequest("POST", "http://localhost/api/skins", nil), 201}, + }, ExpectedCalls: [][]interface{}{ {"IncCounter", "mock_prefix.api.skins.post.success", int64(1)}, }, }, { - Topic: "skinsystem:after_request", - Args: []interface{}{httptest.NewRequest("POST", "http://localhost/api/skins", nil), 400}, + Events: map[string][]interface{}{ + "skinsystem:after_request": {httptest.NewRequest("POST", "http://localhost/api/skins", nil), 400}, + }, ExpectedCalls: [][]interface{}{ {"IncCounter", "mock_prefix.api.skins.post.validation_failed", int64(1)}, }, }, { - Topic: "skinsystem:after_request", - Args: []interface{}{httptest.NewRequest("DELETE", "http://localhost/api/skins/username", nil), 204}, + Events: map[string][]interface{}{ + "skinsystem:after_request": {httptest.NewRequest("DELETE", "http://localhost/api/skins/username", nil), 204}, + }, ExpectedCalls: [][]interface{}{ {"IncCounter", "mock_prefix.api.skins.delete.success", int64(1)}, }, }, { - Topic: "skinsystem:after_request", - Args: []interface{}{httptest.NewRequest("DELETE", "http://localhost/api/skins/username", nil), 404}, + Events: map[string][]interface{}{ + "skinsystem:after_request": {httptest.NewRequest("DELETE", "http://localhost/api/skins/username", nil), 404}, + }, ExpectedCalls: [][]interface{}{ {"IncCounter", "mock_prefix.api.skins.delete.not_found", int64(1)}, }, }, { - Topic: "skinsystem:after_request", - Args: []interface{}{httptest.NewRequest("DELETE", "http://localhost/api/skins/id:1", nil), 204}, + Events: map[string][]interface{}{ + "skinsystem:after_request": {httptest.NewRequest("DELETE", "http://localhost/api/skins/id:1", nil), 204}, + }, ExpectedCalls: [][]interface{}{ {"IncCounter", "mock_prefix.api.skins.delete.success", int64(1)}, }, }, { - Topic: "skinsystem:after_request", - Args: []interface{}{httptest.NewRequest("DELETE", "http://localhost/api/skins/id:1", nil), 404}, + Events: map[string][]interface{}{ + "skinsystem:after_request": {httptest.NewRequest("DELETE", "http://localhost/api/skins/id:1", nil), 404}, + }, ExpectedCalls: [][]interface{}{ {"IncCounter", "mock_prefix.api.skins.delete.not_found", int64(1)}, }, }, { - Topic: "skinsystem:after_request", - Args: []interface{}{httptest.NewRequest("DELETE", "http://localhost/unknown", nil), 404}, + Events: map[string][]interface{}{ + "skinsystem:after_request": {httptest.NewRequest("DELETE", "http://localhost/unknown", nil), 404}, + }, ExpectedCalls: nil, }, // Authenticator { - Topic: "authenticator:success", - Args: []interface{}{}, + Events: map[string][]interface{}{ + "authenticator:success": {}, + }, ExpectedCalls: [][]interface{}{ {"IncCounter", "mock_prefix.authentication.challenge", int64(1)}, {"IncCounter", "mock_prefix.authentication.success", int64(1)}, }, }, { - Topic: "authentication:error", - Args: []interface{}{errors.New("error")}, + Events: map[string][]interface{}{ + "authentication:error": {errors.New("error")}, + }, ExpectedCalls: [][]interface{}{ {"IncCounter", "mock_prefix.authentication.challenge", int64(1)}, {"IncCounter", "mock_prefix.authentication.failed", int64(1)}, }, }, + // Mojang signed textures provider + { + Events: map[string][]interface{}{ + "mojang_textures:before_result": {"username", ""}, + "mojang_textures:after_result": {"username", &mojang.SignedTexturesResponse{}, nilErr}, + }, + ExpectedCalls: [][]interface{}{ + {"RecordTimer", "mock_prefix.mojang_textures.result_time", mock.AnythingOfType("time.Duration")}, + }, + }, + { + Events: map[string][]interface{}{ + "mojang_textures:textures:before_call": {"аааааааааааааааааааааааааааааааа"}, + "mojang_textures:textures:after_call": {"аааааааааааааааааааааааааааааааа", &mojang.SignedTexturesResponse{}, nilErr}, + }, + ExpectedCalls: [][]interface{}{ + {"IncCounter", "mock_prefix.mojang_textures.textures.request", int64(1)}, + {"IncCounter", "mock_prefix.mojang_textures.usernames.textures_hit", int64(1)}, + {"RecordTimer", "mock_prefix.mojang_textures.textures.request_time", mock.AnythingOfType("time.Duration")}, + }, + }, + // Batch UUIDs provider + { + Events: map[string][]interface{}{ + "mojang_textures:batch_uuids_provider:queued": {"username"}, + }, + ExpectedCalls: [][]interface{}{ + {"IncCounter", "mock_prefix.mojang_textures.usernames.queued", int64(1)}, + }, + }, + { + Events: map[string][]interface{}{ + "mojang_textures:batch_uuids_provider:round": {[]string{"username1", "username2"}, 5}, + }, + ExpectedCalls: [][]interface{}{ + {"UpdateGauge", "mock_prefix.mojang_textures.usernames.iteration_size", int64(2)}, + {"UpdateGauge", "mock_prefix.mojang_textures.usernames.queue_size", int64(5)}, + }, + }, + { + Events: map[string][]interface{}{ + "mojang_textures:batch_uuids_provider:before_round": {}, + "mojang_textures:batch_uuids_provider:after_round": {}, + }, + ExpectedCalls: [][]interface{}{ + {"RecordTimer", "mock_prefix.mojang_textures.usernames.round_time", mock.AnythingOfType("time.Duration")}, + }, + }, } -func TestStatsReporter_handleHTTPRequest(t *testing.T) { +func TestStatsReporter_handleEvents(t *testing.T) { for _, c := range statsReporterTestCases { - t.Run(c.Topic, func(t *testing.T) { + t.Run("handle events", func(t *testing.T) { wdMock := &tests.WdMock{} if c.ExpectedCalls != nil { for _, c := range c.ExpectedCalls { @@ -170,7 +253,9 @@ func TestStatsReporter_handleHTTPRequest(t *testing.T) { d := dispatcher.New() reporter.ConfigureWithDispatcher(d) - d.Emit(c.Topic, c.Args...) + for event, args := range c.Events { + d.Emit(event, args...) + } wdMock.AssertExpectations(t) }) From 880182ccbf2829bfceacba61bbe99abb66b819bd Mon Sep 17 00:00:00 2001 From: ErickSkrauch Date: Mon, 30 Mar 2020 15:44:12 +0300 Subject: [PATCH 07/18] Replace event dispatcher by the fork to allow emitting events with nil arguments --- Gopkg.lock | 7 ++++--- Gopkg.toml | 3 ++- eventsubscribers/stats_reporter_test.go | 18 ++---------------- 3 files changed, 8 insertions(+), 20 deletions(-) diff --git a/Gopkg.lock b/Gopkg.lock index 1c46e89..3706dc6 100644 --- a/Gopkg.lock +++ b/Gopkg.lock @@ -15,12 +15,13 @@ version = "1.1" [[projects]] - branch = "master" - digest = "1:33c6f6a0ee7d594d07ad9b67e93266f8a859ab2ddd882f8be19207162f40cce8" + branch = "publish_nil_values" + digest = "1:d02c8323070a3d8d8ca039d0d180198ead0a75eac4fb1003af812435a2b391e8" name = "github.com/asaskevich/EventBus" packages = ["."] pruneopts = "" - revision = "d46933a94f05c6657d7b923fcf5ac563ee37ec79" + revision = "33b3bc6a7ddca2f99683c5c3ee86b24f80a7a075" + source = "https://github.com/erickskrauch/EventBus.git" [[projects]] digest = "1:c7b11da9bf0707e6920e1b361fbbbbe9b277ef3a198377baa4527f6e31049be0" diff --git a/Gopkg.toml b/Gopkg.toml index e851485..b903930 100644 --- a/Gopkg.toml +++ b/Gopkg.toml @@ -37,8 +37,9 @@ ignored = ["github.com/elyby/chrly"] branch = "master" [[constraint]] - branch = "master" name = "github.com/asaskevich/EventBus" + source = "https://github.com/erickskrauch/EventBus.git" + branch = "publish_nil_values" # Testing dependencies diff --git a/eventsubscribers/stats_reporter_test.go b/eventsubscribers/stats_reporter_test.go index fc7e74b..989ca05 100644 --- a/eventsubscribers/stats_reporter_test.go +++ b/eventsubscribers/stats_reporter_test.go @@ -17,20 +17,6 @@ type StatsReporterTestCase struct { ExpectedCalls [][]interface{} } -type NilErr struct { -} - -func (n *NilErr) Error() string { - panic("don't call me") -} - -// This let me to test events with nil error arguments. -// I can't just use `var nilErr error = nil`, because when Golang calls reflect.ValueOf() -// its returns only nil, without type. But when he calls reflection on specific structure (or pointer in this case), -// everything works fine. This is a memorial of 2 hours of my life, debugging and learning from the reflection -// about Go's types system. Nothing to regret. -var nilErr *NilErr = nil - var statsReporterTestCases = []*StatsReporterTestCase{ // Before request { @@ -189,7 +175,7 @@ var statsReporterTestCases = []*StatsReporterTestCase{ { Events: map[string][]interface{}{ "mojang_textures:before_result": {"username", ""}, - "mojang_textures:after_result": {"username", &mojang.SignedTexturesResponse{}, nilErr}, + "mojang_textures:after_result": {"username", &mojang.SignedTexturesResponse{}, nil}, }, ExpectedCalls: [][]interface{}{ {"RecordTimer", "mock_prefix.mojang_textures.result_time", mock.AnythingOfType("time.Duration")}, @@ -198,7 +184,7 @@ var statsReporterTestCases = []*StatsReporterTestCase{ { Events: map[string][]interface{}{ "mojang_textures:textures:before_call": {"аааааааааааааааааааааааааааааааа"}, - "mojang_textures:textures:after_call": {"аааааааааааааааааааааааааааааааа", &mojang.SignedTexturesResponse{}, nilErr}, + "mojang_textures:textures:after_call": {"аааааааааааааааааааааааааааааааа", &mojang.SignedTexturesResponse{}, nil}, }, ExpectedCalls: [][]interface{}{ {"IncCounter", "mock_prefix.mojang_textures.textures.request", int64(1)}, From c5e92e7a02552b1805e4690777ccedff2c79ba42 Mon Sep 17 00:00:00 2001 From: ErickSkrauch Date: Tue, 31 Mar 2020 03:53:46 +0300 Subject: [PATCH 08/18] Added missing tests --- eventsubscribers/stats_reporter_test.go | 102 ++++++++++++++++++++++++ 1 file changed, 102 insertions(+) diff --git a/eventsubscribers/stats_reporter_test.go b/eventsubscribers/stats_reporter_test.go index 989ca05..0bc8ecd 100644 --- a/eventsubscribers/stats_reporter_test.go +++ b/eventsubscribers/stats_reporter_test.go @@ -172,6 +172,108 @@ var statsReporterTestCases = []*StatsReporterTestCase{ }, }, // Mojang signed textures provider + { + Events: map[string][]interface{}{ + "mojang_textures:call": {"username"}, + }, + ExpectedCalls: [][]interface{}{ + {"IncCounter", "mock_prefix.mojang_textures.request", int64(1)}, + }, + }, + { + Events: map[string][]interface{}{ + "mojang_textures:usernames:after_cache": {"username", "", errors.New("error")}, + }, + ExpectedCalls: [][]interface{}{}, + }, + { + Events: map[string][]interface{}{ + "mojang_textures:usernames:after_cache": {"username", "", nil}, + }, + ExpectedCalls: [][]interface{}{ + {"IncCounter", "mock_prefix.mojang_textures:usernames:cache_hit_nil", int64(1)}, + }, + }, + { + Events: map[string][]interface{}{ + "mojang_textures:usernames:after_cache": {"username", "aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa", nil}, + }, + ExpectedCalls: [][]interface{}{ + {"IncCounter", "mock_prefix.mojang_textures:usernames:cache_hit", int64(1)}, + }, + }, + { + Events: map[string][]interface{}{ + "mojang_textures:textures:after_cache": {"aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa", nil, errors.New("error")}, + }, + ExpectedCalls: [][]interface{}{}, + }, + { + Events: map[string][]interface{}{ + "mojang_textures:textures:after_cache": {"aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa", nil, nil}, + }, + ExpectedCalls: [][]interface{}{}, + }, + { + Events: map[string][]interface{}{ + "mojang_textures:textures:after_cache": {"aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa", &mojang.SignedTexturesResponse{}, nil}, + }, + ExpectedCalls: [][]interface{}{ + {"IncCounter", "mock_prefix.mojang_textures.textures.cache_hit", int64(1)}, + }, + }, + { + Events: map[string][]interface{}{ + "mojang_textures:already_processing": {"username"}, + }, + ExpectedCalls: [][]interface{}{ + {"IncCounter", "mock_prefix.mojang_textures.already_scheduled", int64(1)}, + }, + }, + { + Events: map[string][]interface{}{ + "mojang_textures:usernames:after_call": {"username", nil, errors.New("error")}, + }, + ExpectedCalls: [][]interface{}{}, + }, + { + Events: map[string][]interface{}{ + "mojang_textures:usernames:after_call": {"username", nil, nil}, + }, + ExpectedCalls: [][]interface{}{ + {"IncCounter", "mock_prefix.mojang_textures.usernames.uuid_miss", int64(1)}, + }, + }, + { + Events: map[string][]interface{}{ + "mojang_textures:usernames:after_call": {"username", &mojang.ProfileInfo{}, nil}, + }, + ExpectedCalls: [][]interface{}{ + {"IncCounter", "mock_prefix.mojang_textures.usernames.uuid_hit", int64(1)}, + }, + }, + { + Events: map[string][]interface{}{ + "mojang_textures:textures:after_call": {"aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa", nil, errors.New("error")}, + }, + ExpectedCalls: [][]interface{}{}, + }, + { + Events: map[string][]interface{}{ + "mojang_textures:textures:after_call": {"aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa", nil, nil}, + }, + ExpectedCalls: [][]interface{}{ + {"IncCounter", "mock_prefix.mojang_textures.usernames.textures_miss", int64(1)}, + }, + }, + { + Events: map[string][]interface{}{ + "mojang_textures:textures:after_call": {"aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa", &mojang.SignedTexturesResponse{}, nil}, + }, + ExpectedCalls: [][]interface{}{ + {"IncCounter", "mock_prefix.mojang_textures.usernames.textures_hit", int64(1)}, + }, + }, { Events: map[string][]interface{}{ "mojang_textures:before_result": {"username", ""}, From 280a55d553315d8eb825da245e4d62a940e06e2a Mon Sep 17 00:00:00 2001 From: ErickSkrauch Date: Thu, 2 Apr 2020 02:29:14 +0300 Subject: [PATCH 09/18] 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) { From 532f2206dad8f5f0e973be0b717ca58fe73df70a Mon Sep 17 00:00:00 2001 From: ErickSkrauch Date: Thu, 2 Apr 2020 19:34:39 +0300 Subject: [PATCH 10/18] Add simple requests logger (in style of Apache Common log format). Fix Gopkg.lock integrity error. --- Gopkg.lock | 1 + eventsubscribers/logger.go | 20 ++++++++++++++++++++ http/skinsystem.go | 8 ++++++-- 3 files changed, 27 insertions(+), 2 deletions(-) diff --git a/Gopkg.lock b/Gopkg.lock index 3706dc6..7d9c796 100644 --- a/Gopkg.lock +++ b/Gopkg.lock @@ -318,6 +318,7 @@ "github.com/mediocregopher/radix.v2/redis", "github.com/mediocregopher/radix.v2/util", "github.com/mono83/slf", + "github.com/mono83/slf/params", "github.com/mono83/slf/rays", "github.com/mono83/slf/recievers/sentry", "github.com/mono83/slf/recievers/statsd", diff --git a/eventsubscribers/logger.go b/eventsubscribers/logger.go index 2399ae7..f338c3f 100644 --- a/eventsubscribers/logger.go +++ b/eventsubscribers/logger.go @@ -2,6 +2,7 @@ package eventsubscribers import ( "net" + "net/http" "net/url" "syscall" @@ -17,10 +18,29 @@ type Logger struct { } func (l *Logger) ConfigureWithDispatcher(d dispatcher.EventDispatcher) { + d.Subscribe("skinsystem:after_request", l.handleAfterSkinsystemRequest) + d.Subscribe("mojang_textures:usernames:after_call", l.createMojangTexturesErrorHandler("usernames")) d.Subscribe("mojang_textures:textures:after_call", l.createMojangTexturesErrorHandler("textures")) } +func (l *Logger) handleAfterSkinsystemRequest(req *http.Request, statusCode int) { + forwardedIp := req.Header.Get("X-Forwarded-For") + if forwardedIp == "" { + forwardedIp = req.Header.Get("X-Real-Ip") + } + + l.Info( + ":ip - - \":method :path\" :statusCode \":userAgent\" \":forwardedIp\"", + wd.StringParam("ip", req.RemoteAddr), + wd.StringParam("method", req.Method), + wd.StringParam("path", req.URL.Path), + wd.IntParam("statusCode", statusCode), + wd.StringParam("userAgent", req.UserAgent()), + wd.StringParam("forwardedIp", forwardedIp), + ) +} + 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) { diff --git a/http/skinsystem.go b/http/skinsystem.go index a5c6f11..a7829a0 100644 --- a/http/skinsystem.go +++ b/http/skinsystem.go @@ -89,8 +89,10 @@ type Skinsystem struct { } func (ctx *Skinsystem) CreateHandler() *mux.Router { + requestEventsMiddleware := CreateRequestEventsMiddleware(ctx.Emitter, "skinsystem") + router := mux.NewRouter().StrictSlash(true) - router.Use(CreateRequestEventsMiddleware(ctx.Emitter, "skinsystem")) + router.Use(requestEventsMiddleware) router.HandleFunc("/skins/{username}", ctx.Skin).Methods(http.MethodGet) router.HandleFunc("/cloaks/{username}", ctx.Cape).Methods(http.MethodGet).Name("cloaks") @@ -106,7 +108,9 @@ func (ctx *Skinsystem) CreateHandler() *mux.Router { apiRouter.HandleFunc("/skins/id:{id:[0-9]+}", ctx.DeleteSkinByUserId).Methods(http.MethodDelete) apiRouter.HandleFunc("/skins/{username}", ctx.DeleteSkinByUsername).Methods(http.MethodDelete) // 404 - router.NotFoundHandler = http.HandlerFunc(NotFound) + // NotFoundHandler doesn't call for registered middlewares, so we must wrap it manually. + // See https://github.com/gorilla/mux/issues/416#issuecomment-600079279 + router.NotFoundHandler = requestEventsMiddleware(http.HandlerFunc(NotFound)) return router } From 20a8d90ad700b58a8963fb61bf72949055c892df Mon Sep 17 00:00:00 2001 From: ErickSkrauch Date: Fri, 3 Apr 2020 17:18:02 +0300 Subject: [PATCH 11/18] Add tests for requests logger --- eventsubscribers/logger.go | 22 +++++++---- eventsubscribers/logger_test.go | 70 ++++++++++++++++++++++++++++++++- 2 files changed, 84 insertions(+), 8 deletions(-) diff --git a/eventsubscribers/logger.go b/eventsubscribers/logger.go index f338c3f..ad8d330 100644 --- a/eventsubscribers/logger.go +++ b/eventsubscribers/logger.go @@ -4,6 +4,7 @@ import ( "net" "net/http" "net/url" + "strings" "syscall" "github.com/mono83/slf" @@ -25,19 +26,19 @@ func (l *Logger) ConfigureWithDispatcher(d dispatcher.EventDispatcher) { } func (l *Logger) handleAfterSkinsystemRequest(req *http.Request, statusCode int) { - forwardedIp := req.Header.Get("X-Forwarded-For") - if forwardedIp == "" { - forwardedIp = req.Header.Get("X-Real-Ip") + path := req.URL.Path + if req.URL.RawQuery != "" { + path += "?" + req.URL.RawQuery } l.Info( - ":ip - - \":method :path\" :statusCode \":userAgent\" \":forwardedIp\"", - wd.StringParam("ip", req.RemoteAddr), + ":ip - - \":method :path\" :statusCode - \":userAgent\" \":forwardedIp\"", + wd.StringParam("ip", trimPort(req.RemoteAddr)), wd.StringParam("method", req.Method), - wd.StringParam("path", req.URL.Path), + wd.StringParam("path", path), wd.IntParam("statusCode", statusCode), wd.StringParam("userAgent", req.UserAgent()), - wd.StringParam("forwardedIp", forwardedIp), + wd.StringParam("forwardedIp", req.Header.Get("X-Forwarded-For")), ) } @@ -87,3 +88,10 @@ func (l *Logger) createMojangTexturesErrorHandler(provider string) func(identity func (l *Logger) logMojangTexturesWarning(providerParam slf.Param, errParam slf.Param) { l.Warning(":name: :err", providerParam, errParam) } + +func trimPort(ip string) string { + // Don't care about possible -1 result because RemoteAddr will always contain ip and port + cutTo := strings.LastIndexByte(ip, ':') + + return ip[0:cutTo] +} diff --git a/eventsubscribers/logger_test.go b/eventsubscribers/logger_test.go index 42062a9..40a3248 100644 --- a/eventsubscribers/logger_test.go +++ b/eventsubscribers/logger_test.go @@ -2,6 +2,8 @@ package eventsubscribers import ( "net" + "net/http" + "net/http/httptest" "net/url" "syscall" "testing" @@ -19,7 +21,73 @@ type LoggerTestCase struct { ExpectedCalls [][]interface{} } -var loggerTestCases = map[string]*LoggerTestCase{} +var loggerTestCases = map[string]*LoggerTestCase{ + "should log each request to the skinsystem": { + Events: [][]interface{}{ + {"skinsystem:after_request", + (func() *http.Request { + req := httptest.NewRequest("GET", "http://localhost/skins/username.png", nil) + req.Header.Add("User-Agent", "Test user agent") + + return req + })(), + 201, + }, + }, + ExpectedCalls: [][]interface{}{ + {"Info", + ":ip - - \":method :path\" :statusCode - \":userAgent\" \":forwardedIp\"", + mock.MatchedBy(func(strParam params.String) bool { + return strParam.Key == "ip" && strParam.Value == "192.0.2.1" + }), + mock.MatchedBy(func(strParam params.String) bool { + return strParam.Key == "method" && strParam.Value == "GET" + }), + mock.MatchedBy(func(strParam params.String) bool { + return strParam.Key == "path" && strParam.Value == "/skins/username.png" + }), + mock.MatchedBy(func(strParam params.Int) bool { + return strParam.Key == "statusCode" && strParam.Value == 201 + }), + mock.MatchedBy(func(strParam params.String) bool { + return strParam.Key == "userAgent" && strParam.Value == "Test user agent" + }), + mock.MatchedBy(func(strParam params.String) bool { + return strParam.Key == "forwardedIp" && strParam.Value == "" + }), + }, + }, + }, + "should log each request to the skinsystem 2": { + Events: [][]interface{}{ + {"skinsystem:after_request", + (func() *http.Request { + req := httptest.NewRequest("GET", "http://localhost/skins/username.png?authlib=1.5.2", nil) + req.Header.Add("User-Agent", "Test user agent") + req.Header.Add("X-Forwarded-For", "1.2.3.4") + + return req + })(), + 201, + }, + }, + ExpectedCalls: [][]interface{}{ + {"Info", + ":ip - - \":method :path\" :statusCode - \":userAgent\" \":forwardedIp\"", + mock.Anything, // Already tested + mock.Anything, // Already tested + mock.MatchedBy(func(strParam params.String) bool { + return strParam.Key == "path" && strParam.Value == "/skins/username.png?authlib=1.5.2" + }), + mock.Anything, // Already tested + mock.Anything, // Already tested + mock.MatchedBy(func(strParam params.String) bool { + return strParam.Key == "forwardedIp" && strParam.Value == "1.2.3.4" + }), + }, + }, + }, +} type timeoutError struct{} From bd134801759fedeec400f28ef4469c2dee41355c Mon Sep 17 00:00:00 2001 From: ErickSkrauch Date: Fri, 3 Apr 2020 20:23:34 +0300 Subject: [PATCH 12/18] Added uuid normalization for mojang's uuid to textures request --- api/mojang/mojang.go | 4 +++- api/mojang/mojang_test.go | 4 ++-- 2 files changed, 5 insertions(+), 3 deletions(-) diff --git a/api/mojang/mojang.go b/api/mojang/mojang.go index 5e90566..7527b97 100644 --- a/api/mojang/mojang.go +++ b/api/mojang/mojang.go @@ -6,6 +6,7 @@ import ( "fmt" "io/ioutil" "net/http" + "strings" "time" ) @@ -86,7 +87,8 @@ func UsernamesToUuids(usernames []string) ([]*ProfileInfo, error) { // Obtains textures information for provided uuid // See https://wiki.vg/Mojang_API#UUID_-.3E_Profile_.2B_Skin.2FCape func UuidToTextures(uuid string, signed bool) (*SignedTexturesResponse, error) { - url := "https://sessionserver.mojang.com/session/minecraft/profile/" + uuid + normalizedUuid := strings.ReplaceAll(uuid, "-", "") + url := "https://sessionserver.mojang.com/session/minecraft/profile/" + normalizedUuid if signed { url += "?unsigned=false" } diff --git a/api/mojang/mojang_test.go b/api/mojang/mojang_test.go index 44c7a96..b2756ca 100644 --- a/api/mojang/mojang_test.go +++ b/api/mojang/mojang_test.go @@ -205,7 +205,7 @@ func TestUuidToTextures(t *testing.T) { } }) - t.Run("obtain signed textures", func(t *testing.T) { + t.Run("obtain signed textures with dashed uuid", func(t *testing.T) { assert := testify.New(t) defer gock.Off() @@ -230,7 +230,7 @@ func TestUuidToTextures(t *testing.T) { HttpClient = client - result, err := UuidToTextures("4566e69fc90748ee8d71d7ba5aa00d20", true) + result, err := UuidToTextures("4566e69f-c907-48ee-8d71-d7ba5aa00d20", true) if assert.NoError(err) { assert.Equal("4566e69fc90748ee8d71d7ba5aa00d20", result.Id) assert.Equal("Thinkofdeath", result.Name) From 49a1aaada0bbaee4b0bce35091b3dfe38337d2a0 Mon Sep 17 00:00:00 2001 From: ErickSkrauch Date: Fri, 3 Apr 2020 22:20:56 +0300 Subject: [PATCH 13/18] Cleanup: remove tests and scripts folders. Introduce Subscriber interface to make eventsubscriber package independent of package dispatcher. --- README.md | 2 +- eventsubscribers/logger.go | 3 +- eventsubscribers/logger_test.go | 51 +++++++++++++++-- eventsubscribers/stats_reporter.go | 3 +- eventsubscribers/stats_reporter_test.go | 43 ++++++++++++-- eventsubscribers/subscriber.go | 5 ++ script/coverage | 46 --------------- script/test | 27 --------- tests/wd_mock.go | 74 ------------------------- 9 files changed, 91 insertions(+), 163 deletions(-) create mode 100644 eventsubscribers/subscriber.go delete mode 100755 script/coverage delete mode 100755 script/test delete mode 100644 tests/wd_mock.go diff --git a/README.md b/README.md index 680e8dc..1669d35 100644 --- a/README.md +++ b/README.md @@ -342,7 +342,7 @@ If your Redis instance isn't located at the `localhost`, you can change host by `STORAGE_REDIS_HOST`. After all of that `go run main.go serve` should successfully start the application. -To run tests execute `go test ./...`. If your Go version is older than 1.9, then run a `/script/test`. +To run tests execute `go test ./...`. [ico-lang]: https://img.shields.io/badge/lang-go%201.13-blue.svg?style=flat-square [ico-build]: https://img.shields.io/travis/elyby/chrly.svg?style=flat-square diff --git a/eventsubscribers/logger.go b/eventsubscribers/logger.go index ad8d330..357fa98 100644 --- a/eventsubscribers/logger.go +++ b/eventsubscribers/logger.go @@ -11,14 +11,13 @@ import ( "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) { +func (l *Logger) ConfigureWithDispatcher(d Subscriber) { d.Subscribe("skinsystem:after_request", l.handleAfterSkinsystemRequest) d.Subscribe("mojang_textures:usernames:after_call", l.createMojangTexturesErrorHandler("usernames")) diff --git a/eventsubscribers/logger_test.go b/eventsubscribers/logger_test.go index 40a3248..e892234 100644 --- a/eventsubscribers/logger_test.go +++ b/eventsubscribers/logger_test.go @@ -8,14 +8,55 @@ import ( "syscall" "testing" + "github.com/mono83/slf" "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 LoggerMock struct { + mock.Mock +} + +func prepareLoggerArgs(message string, params []slf.Param) []interface{} { + args := []interface{}{message} + for _, v := range params { + args = append(args, v.(interface{})) + } + + return args +} + +func (l *LoggerMock) Trace(message string, params ...slf.Param) { + l.Called(prepareLoggerArgs(message, params)...) +} + +func (l *LoggerMock) Debug(message string, params ...slf.Param) { + l.Called(prepareLoggerArgs(message, params)...) +} + +func (l *LoggerMock) Info(message string, params ...slf.Param) { + l.Called(prepareLoggerArgs(message, params)...) +} + +func (l *LoggerMock) Warning(message string, params ...slf.Param) { + l.Called(prepareLoggerArgs(message, params)...) +} + +func (l *LoggerMock) Error(message string, params ...slf.Param) { + l.Called(prepareLoggerArgs(message, params)...) +} + +func (l *LoggerMock) Alert(message string, params ...slf.Param) { + l.Called(prepareLoggerArgs(message, params)...) +} + +func (l *LoggerMock) Emergency(message string, params ...slf.Param) { + l.Called(prepareLoggerArgs(message, params)...) +} + type LoggerTestCase struct { Events [][]interface{} ExpectedCalls [][]interface{} @@ -189,16 +230,16 @@ func init() { func TestLogger(t *testing.T) { for name, c := range loggerTestCases { t.Run(name, func(t *testing.T) { - wdMock := &tests.WdMock{} + loggerMock := &LoggerMock{} if c.ExpectedCalls != nil { for _, c := range c.ExpectedCalls { topicName, _ := c[0].(string) - wdMock.On(topicName, c[1:]...) + loggerMock.On(topicName, c[1:]...) } } reporter := &Logger{ - Logger: wdMock, + Logger: loggerMock, } d := dispatcher.New() @@ -211,7 +252,7 @@ func TestLogger(t *testing.T) { if c.ExpectedCalls != nil { for _, c := range c.ExpectedCalls { topicName, _ := c[0].(string) - wdMock.AssertCalled(t, topicName, c[1:]...) + loggerMock.AssertCalled(t, topicName, c[1:]...) } } }) diff --git a/eventsubscribers/stats_reporter.go b/eventsubscribers/stats_reporter.go index 2a1ce2b..76f0994 100644 --- a/eventsubscribers/stats_reporter.go +++ b/eventsubscribers/stats_reporter.go @@ -9,7 +9,6 @@ import ( "github.com/mono83/slf" "github.com/elyby/chrly/api/mojang" - "github.com/elyby/chrly/dispatcher" ) type StatsReporter struct { @@ -19,7 +18,7 @@ type StatsReporter struct { timersMap sync.Map } -func (s *StatsReporter) ConfigureWithDispatcher(d dispatcher.EventDispatcher) { +func (s *StatsReporter) ConfigureWithDispatcher(d Subscriber) { // Per request events d.Subscribe("skinsystem:before_request", s.handleBeforeRequest) d.Subscribe("skinsystem:after_request", s.handleAfterRequest) diff --git a/eventsubscribers/stats_reporter_test.go b/eventsubscribers/stats_reporter_test.go index 51b5b93..fd15ce8 100644 --- a/eventsubscribers/stats_reporter_test.go +++ b/eventsubscribers/stats_reporter_test.go @@ -4,14 +4,45 @@ import ( "errors" "net/http/httptest" "testing" + "time" - "github.com/stretchr/testify/mock" + "github.com/mono83/slf" "github.com/elyby/chrly/api/mojang" "github.com/elyby/chrly/dispatcher" - "github.com/elyby/chrly/tests" + + "github.com/stretchr/testify/mock" ) +func prepareStatsReporterArgs(name string, value interface{}, params []slf.Param) []interface{} { + args := []interface{}{name, value} + for _, v := range params { + args = append(args, v.(interface{})) + } + + return args +} + +type StatsReporterMock struct { + mock.Mock +} + +func (r *StatsReporterMock) IncCounter(name string, value int64, params ...slf.Param) { + r.Called(prepareStatsReporterArgs(name, value, params)...) +} + +func (r *StatsReporterMock) UpdateGauge(name string, value int64, params ...slf.Param) { + r.Called(prepareStatsReporterArgs(name, value, params)...) +} + +func (r *StatsReporterMock) RecordTimer(name string, duration time.Duration, params ...slf.Param) { + r.Called(prepareStatsReporterArgs(name, duration, params)...) +} + +func (r *StatsReporterMock) Timer(name string, params ...slf.Param) slf.Timer { + return slf.NewTimer(name, params, r) +} + type StatsReporterTestCase struct { Events map[string][]interface{} ExpectedCalls [][]interface{} @@ -326,16 +357,16 @@ var statsReporterTestCases = []*StatsReporterTestCase{ func TestStatsReporter(t *testing.T) { for _, c := range statsReporterTestCases { t.Run("handle events", func(t *testing.T) { - wdMock := &tests.WdMock{} + statsReporterMock := &StatsReporterMock{} if c.ExpectedCalls != nil { for _, c := range c.ExpectedCalls { topicName, _ := c[0].(string) - wdMock.On(topicName, c[1:]...).Once() + statsReporterMock.On(topicName, c[1:]...).Once() } } reporter := &StatsReporter{ - Reporter: wdMock, + Reporter: statsReporterMock, Prefix: "mock_prefix", } @@ -345,7 +376,7 @@ func TestStatsReporter(t *testing.T) { d.Emit(event, args...) } - wdMock.AssertExpectations(t) + statsReporterMock.AssertExpectations(t) }) } } diff --git a/eventsubscribers/subscriber.go b/eventsubscribers/subscriber.go new file mode 100644 index 0000000..8b64092 --- /dev/null +++ b/eventsubscribers/subscriber.go @@ -0,0 +1,5 @@ +package eventsubscribers + +type Subscriber interface { + Subscribe(topic string, fn interface{}) +} diff --git a/script/coverage b/script/coverage deleted file mode 100755 index 680e4fb..0000000 --- a/script/coverage +++ /dev/null @@ -1,46 +0,0 @@ -#!/bin/sh -# Based on https://github.com/mlafeldt/chef-runner/blob/34269dbb726c243dff9764007e7bd7f0fe9ee331/script/coverage -# Generate test coverage statistics for Go packages. -# -# Works around the fact that `go test -coverprofile` currently does not work -# with multiple packages, see https://code.google.com/p/go/issues/detail?id=6909 -# -# Usage: script/coverage [--html] -# -# --html Additionally create HTML report and open it in browser -# - -set -e - -workdir=.cover -profile="$workdir/cover.out" -mode=count - -generate_cover_data() { - rm -rf "$workdir" - mkdir "$workdir" - - go test -i "$@" # compile dependencies first before serializing go test invocations - for pkg in "$@"; do - f="$workdir/$(echo $pkg | tr / -).cover" - go test -covermode="$mode" -coverprofile="$f" "$pkg" - done - - echo "mode: $mode" >"$profile" - grep -h -v "^mode:" "$workdir"/*.cover >>"$profile" -} - -show_cover_report() { - go tool cover -${1}="$profile" -} - -generate_cover_data $(go list ./... | grep -v /vendor/) -show_cover_report func -case "$1" in -"") - ;; ---html) - show_cover_report html ;; -*) - echo >&2 "error: invalid option: $1"; exit 1 ;; -esac diff --git a/script/test b/script/test deleted file mode 100755 index fd4a6b4..0000000 --- a/script/test +++ /dev/null @@ -1,27 +0,0 @@ -#!/bin/sh -# Based on https://github.com/mlafeldt/chef-runner/blob/34269dbb726c243dff9764007e7bd7f0fe9ee331/script/test -# Run package tests for a file/directory, or all tests if no argument is passed. -# Useful to e.g. execute package tests for the file currently open in Vim. -# Usage: script/test [path] - -set -e - -go_pkg_from_path() { - path=$1 - if test -d "$path"; then - dir="$path" - else - dir=$(dirname "$path") - fi - (cd "$dir" && go list) -} - -if test $# -gt 0; then - pkg=$(go_pkg_from_path "$1") - verbose=-v -else - pkg=$(go list ./... | grep -v /vendor/) - verbose= -fi - -exec go test ${GOTESTOPTS:-$verbose} $pkg diff --git a/tests/wd_mock.go b/tests/wd_mock.go deleted file mode 100644 index 62d7bd1..0000000 --- a/tests/wd_mock.go +++ /dev/null @@ -1,74 +0,0 @@ -package tests - -import ( - "time" - - "github.com/mono83/slf" - "github.com/mono83/slf/wd" - "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, params ...slf.Param) { - m.Called(prepareLoggerArgs(message, params)...) -} - -func (m *WdMock) Debug(message string, params ...slf.Param) { - m.Called(prepareLoggerArgs(message, params)...) -} - -func (m *WdMock) Info(message string, params ...slf.Param) { - m.Called(prepareLoggerArgs(message, params)...) -} - -func (m *WdMock) Warning(message string, params ...slf.Param) { - m.Called(prepareLoggerArgs(message, params)...) -} - -func (m *WdMock) Error(message string, params ...slf.Param) { - m.Called(prepareLoggerArgs(message, params)...) -} - -func (m *WdMock) Alert(message string, params ...slf.Param) { - m.Called(prepareLoggerArgs(message, params)...) -} - -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) { - m.Called(name, value) -} - -func (m *WdMock) UpdateGauge(name string, value int64, p ...slf.Param) { - m.Called(name, value) -} - -func (m *WdMock) RecordTimer(name string, d time.Duration, p ...slf.Param) { - m.Called(name, d) -} - -func (m *WdMock) Timer(name string, p ...slf.Param) slf.Timer { - return slf.NewTimer(name, p, m) -} - -func (m *WdMock) WithParams(p ...slf.Param) wd.Watchdog { - panic("this method shouldn't be used") -} From 336fcdd072e91eb644b414bcbb1cb1dda331c5f7 Mon Sep 17 00:00:00 2001 From: ErickSkrauch Date: Fri, 3 Apr 2020 23:03:15 +0300 Subject: [PATCH 14/18] Replace map with slice in stats_reporter test to avoid maps randomized order --- eventsubscribers/stats_reporter.go | 28 ++-- eventsubscribers/stats_reporter_test.go | 169 ++++++++++++------------ 2 files changed, 101 insertions(+), 96 deletions(-) diff --git a/eventsubscribers/stats_reporter.go b/eventsubscribers/stats_reporter.go index 76f0994..ca1c18d 100644 --- a/eventsubscribers/stats_reporter.go +++ b/eventsubscribers/stats_reporter.go @@ -12,13 +12,16 @@ import ( ) type StatsReporter struct { - Reporter slf.StatsReporter - Prefix string + slf.StatsReporter + Prefix string - timersMap sync.Map + timersMap map[string]time.Time + timersMutex sync.Mutex } func (s *StatsReporter) ConfigureWithDispatcher(d Subscriber) { + s.timersMap = make(map[string]time.Time) + // Per request events d.Subscribe("skinsystem:before_request", s.handleBeforeRequest) d.Subscribe("skinsystem:after_request", s.handleAfterRequest) @@ -155,33 +158,34 @@ func (s *StatsReporter) incCounterHandler(name string) func(...interface{}) { } func (s *StatsReporter) startTimeRecording(timeKey string) { - s.timersMap.Store(timeKey, time.Now()) + s.timersMutex.Lock() + defer s.timersMutex.Unlock() + s.timersMap[timeKey] = time.Now() } func (s *StatsReporter) finalizeTimeRecording(timeKey string, statName string) { - startedAtUncasted, ok := s.timersMap.Load(timeKey) + s.timersMutex.Lock() + defer s.timersMutex.Unlock() + startedAt, ok := s.timersMap[timeKey] if !ok { return } - startedAt, ok := startedAtUncasted.(time.Time) - if !ok { - panic("unable to cast map value to the time.Time") - } + delete(s.timersMap, timeKey) s.recordTimer(statName, time.Since(startedAt)) } func (s *StatsReporter) incCounter(name string) { - s.Reporter.IncCounter(s.key(name), 1) + s.IncCounter(s.key(name), 1) } func (s *StatsReporter) updateGauge(name string, value int64) { - s.Reporter.UpdateGauge(s.key(name), value) + s.UpdateGauge(s.key(name), value) } func (s *StatsReporter) recordTimer(name string, duration time.Duration) { - s.Reporter.RecordTimer(s.key(name), duration) + s.RecordTimer(s.key(name), duration) } func (s *StatsReporter) key(name string) string { diff --git a/eventsubscribers/stats_reporter_test.go b/eventsubscribers/stats_reporter_test.go index fd15ce8..a8ff3c5 100644 --- a/eventsubscribers/stats_reporter_test.go +++ b/eventsubscribers/stats_reporter_test.go @@ -44,149 +44,149 @@ func (r *StatsReporterMock) Timer(name string, params ...slf.Param) slf.Timer { } type StatsReporterTestCase struct { - Events map[string][]interface{} + Events [][]interface{} ExpectedCalls [][]interface{} } var statsReporterTestCases = []*StatsReporterTestCase{ // Before request { - Events: map[string][]interface{}{ - "skinsystem:before_request": {httptest.NewRequest("GET", "http://localhost/skins/username", nil)}, + Events: [][]interface{}{ + {"skinsystem:before_request", httptest.NewRequest("GET", "http://localhost/skins/username", nil)}, }, ExpectedCalls: [][]interface{}{ {"IncCounter", "mock_prefix.skins.request", int64(1)}, }, }, { - Events: map[string][]interface{}{ - "skinsystem:before_request": {httptest.NewRequest("GET", "http://localhost/skins?name=username", nil)}, + Events: [][]interface{}{ + {"skinsystem:before_request", httptest.NewRequest("GET", "http://localhost/skins?name=username", nil)}, }, ExpectedCalls: [][]interface{}{ {"IncCounter", "mock_prefix.skins.get_request", int64(1)}, }, }, { - Events: map[string][]interface{}{ - "skinsystem:before_request": {httptest.NewRequest("GET", "http://localhost/cloaks/username", nil)}, + Events: [][]interface{}{ + {"skinsystem:before_request", httptest.NewRequest("GET", "http://localhost/cloaks/username", nil)}, }, ExpectedCalls: [][]interface{}{ {"IncCounter", "mock_prefix.capes.request", int64(1)}, }, }, { - Events: map[string][]interface{}{ - "skinsystem:before_request": {httptest.NewRequest("GET", "http://localhost/cloaks?name=username", nil)}, + Events: [][]interface{}{ + {"skinsystem:before_request", httptest.NewRequest("GET", "http://localhost/cloaks?name=username", nil)}, }, ExpectedCalls: [][]interface{}{ {"IncCounter", "mock_prefix.capes.get_request", int64(1)}, }, }, { - Events: map[string][]interface{}{ - "skinsystem:before_request": {httptest.NewRequest("GET", "http://localhost/textures/username", nil)}, + Events: [][]interface{}{ + {"skinsystem:before_request", httptest.NewRequest("GET", "http://localhost/textures/username", nil)}, }, ExpectedCalls: [][]interface{}{ {"IncCounter", "mock_prefix.textures.request", int64(1)}, }, }, { - Events: map[string][]interface{}{ - "skinsystem:before_request": {httptest.NewRequest("GET", "http://localhost/textures/signed/username", nil)}, + Events: [][]interface{}{ + {"skinsystem:before_request", httptest.NewRequest("GET", "http://localhost/textures/signed/username", nil)}, }, ExpectedCalls: [][]interface{}{ {"IncCounter", "mock_prefix.signed_textures.request", int64(1)}, }, }, { - Events: map[string][]interface{}{ - "skinsystem:before_request": {httptest.NewRequest("POST", "http://localhost/api/skins", nil)}, + Events: [][]interface{}{ + {"skinsystem:before_request", httptest.NewRequest("POST", "http://localhost/api/skins", nil)}, }, ExpectedCalls: [][]interface{}{ {"IncCounter", "mock_prefix.api.skins.post.request", int64(1)}, }, }, { - Events: map[string][]interface{}{ - "skinsystem:before_request": {httptest.NewRequest("DELETE", "http://localhost/api/skins/username", nil)}, + Events: [][]interface{}{ + {"skinsystem:before_request", httptest.NewRequest("DELETE", "http://localhost/api/skins/username", nil)}, }, ExpectedCalls: [][]interface{}{ {"IncCounter", "mock_prefix.api.skins.delete.request", int64(1)}, }, }, { - Events: map[string][]interface{}{ - "skinsystem:before_request": {httptest.NewRequest("DELETE", "http://localhost/api/skins/id:1", nil)}, + Events: [][]interface{}{ + {"skinsystem:before_request", httptest.NewRequest("DELETE", "http://localhost/api/skins/id:1", nil)}, }, ExpectedCalls: [][]interface{}{ {"IncCounter", "mock_prefix.api.skins.delete.request", int64(1)}, }, }, { - Events: map[string][]interface{}{ - "skinsystem:before_request": {httptest.NewRequest("GET", "http://localhost/unknown", nil)}, + Events: [][]interface{}{ + {"skinsystem:before_request", httptest.NewRequest("GET", "http://localhost/unknown", nil)}, }, ExpectedCalls: nil, }, // After request { - Events: map[string][]interface{}{ - "skinsystem:after_request": {httptest.NewRequest("POST", "http://localhost/api/skins", nil), 201}, + Events: [][]interface{}{ + {"skinsystem:after_request", httptest.NewRequest("POST", "http://localhost/api/skins", nil), 201}, }, ExpectedCalls: [][]interface{}{ {"IncCounter", "mock_prefix.api.skins.post.success", int64(1)}, }, }, { - Events: map[string][]interface{}{ - "skinsystem:after_request": {httptest.NewRequest("POST", "http://localhost/api/skins", nil), 400}, + Events: [][]interface{}{ + {"skinsystem:after_request", httptest.NewRequest("POST", "http://localhost/api/skins", nil), 400}, }, ExpectedCalls: [][]interface{}{ {"IncCounter", "mock_prefix.api.skins.post.validation_failed", int64(1)}, }, }, { - Events: map[string][]interface{}{ - "skinsystem:after_request": {httptest.NewRequest("DELETE", "http://localhost/api/skins/username", nil), 204}, + Events: [][]interface{}{ + {"skinsystem:after_request", httptest.NewRequest("DELETE", "http://localhost/api/skins/username", nil), 204}, }, ExpectedCalls: [][]interface{}{ {"IncCounter", "mock_prefix.api.skins.delete.success", int64(1)}, }, }, { - Events: map[string][]interface{}{ - "skinsystem:after_request": {httptest.NewRequest("DELETE", "http://localhost/api/skins/username", nil), 404}, + Events: [][]interface{}{ + {"skinsystem:after_request", httptest.NewRequest("DELETE", "http://localhost/api/skins/username", nil), 404}, }, ExpectedCalls: [][]interface{}{ {"IncCounter", "mock_prefix.api.skins.delete.not_found", int64(1)}, }, }, { - Events: map[string][]interface{}{ - "skinsystem:after_request": {httptest.NewRequest("DELETE", "http://localhost/api/skins/id:1", nil), 204}, + Events: [][]interface{}{ + {"skinsystem:after_request", httptest.NewRequest("DELETE", "http://localhost/api/skins/id:1", nil), 204}, }, ExpectedCalls: [][]interface{}{ {"IncCounter", "mock_prefix.api.skins.delete.success", int64(1)}, }, }, { - Events: map[string][]interface{}{ - "skinsystem:after_request": {httptest.NewRequest("DELETE", "http://localhost/api/skins/id:1", nil), 404}, + Events: [][]interface{}{ + {"skinsystem:after_request", httptest.NewRequest("DELETE", "http://localhost/api/skins/id:1", nil), 404}, }, ExpectedCalls: [][]interface{}{ {"IncCounter", "mock_prefix.api.skins.delete.not_found", int64(1)}, }, }, { - Events: map[string][]interface{}{ - "skinsystem:after_request": {httptest.NewRequest("DELETE", "http://localhost/unknown", nil), 404}, + Events: [][]interface{}{ + {"skinsystem:after_request", httptest.NewRequest("DELETE", "http://localhost/unknown", nil), 404}, }, ExpectedCalls: nil, }, // Authenticator { - Events: map[string][]interface{}{ - "authenticator:success": {}, + Events: [][]interface{}{ + {"authenticator:success"}, }, ExpectedCalls: [][]interface{}{ {"IncCounter", "mock_prefix.authentication.challenge", int64(1)}, @@ -194,8 +194,8 @@ var statsReporterTestCases = []*StatsReporterTestCase{ }, }, { - Events: map[string][]interface{}{ - "authentication:error": {errors.New("error")}, + Events: [][]interface{}{ + {"authentication:error", errors.New("error")}, }, ExpectedCalls: [][]interface{}{ {"IncCounter", "mock_prefix.authentication.challenge", int64(1)}, @@ -204,120 +204,120 @@ var statsReporterTestCases = []*StatsReporterTestCase{ }, // Mojang signed textures provider { - Events: map[string][]interface{}{ - "mojang_textures:call": {"username"}, + Events: [][]interface{}{ + {"mojang_textures:call", "username"}, }, ExpectedCalls: [][]interface{}{ {"IncCounter", "mock_prefix.mojang_textures.request", int64(1)}, }, }, { - Events: map[string][]interface{}{ - "mojang_textures:usernames:after_cache": {"username", "", errors.New("error")}, + Events: [][]interface{}{ + {"mojang_textures:usernames:after_cache", "username", "", errors.New("error")}, }, ExpectedCalls: [][]interface{}{}, }, { - Events: map[string][]interface{}{ - "mojang_textures:usernames:after_cache": {"username", "", nil}, + Events: [][]interface{}{ + {"mojang_textures:usernames:after_cache", "username", "", nil}, }, ExpectedCalls: [][]interface{}{ {"IncCounter", "mock_prefix.mojang_textures:usernames:cache_hit_nil", int64(1)}, }, }, { - Events: map[string][]interface{}{ - "mojang_textures:usernames:after_cache": {"username", "aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa", nil}, + Events: [][]interface{}{ + {"mojang_textures:usernames:after_cache", "username", "aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa", nil}, }, ExpectedCalls: [][]interface{}{ {"IncCounter", "mock_prefix.mojang_textures:usernames:cache_hit", int64(1)}, }, }, { - Events: map[string][]interface{}{ - "mojang_textures:textures:after_cache": {"aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa", nil, errors.New("error")}, + Events: [][]interface{}{ + {"mojang_textures:textures:after_cache", "aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa", nil, errors.New("error")}, }, ExpectedCalls: [][]interface{}{}, }, { - Events: map[string][]interface{}{ - "mojang_textures:textures:after_cache": {"aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa", nil, nil}, + Events: [][]interface{}{ + {"mojang_textures:textures:after_cache", "aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa", nil, nil}, }, ExpectedCalls: [][]interface{}{}, }, { - Events: map[string][]interface{}{ - "mojang_textures:textures:after_cache": {"aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa", &mojang.SignedTexturesResponse{}, nil}, + Events: [][]interface{}{ + {"mojang_textures:textures:after_cache", "aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa", &mojang.SignedTexturesResponse{}, nil}, }, ExpectedCalls: [][]interface{}{ {"IncCounter", "mock_prefix.mojang_textures.textures.cache_hit", int64(1)}, }, }, { - Events: map[string][]interface{}{ - "mojang_textures:already_processing": {"username"}, + Events: [][]interface{}{ + {"mojang_textures:already_processing", "username"}, }, ExpectedCalls: [][]interface{}{ {"IncCounter", "mock_prefix.mojang_textures.already_scheduled", int64(1)}, }, }, { - Events: map[string][]interface{}{ - "mojang_textures:usernames:after_call": {"username", nil, errors.New("error")}, + Events: [][]interface{}{ + {"mojang_textures:usernames:after_call", "username", nil, errors.New("error")}, }, ExpectedCalls: [][]interface{}{}, }, { - Events: map[string][]interface{}{ - "mojang_textures:usernames:after_call": {"username", nil, nil}, + Events: [][]interface{}{ + {"mojang_textures:usernames:after_call", "username", nil, nil}, }, ExpectedCalls: [][]interface{}{ {"IncCounter", "mock_prefix.mojang_textures.usernames.uuid_miss", int64(1)}, }, }, { - Events: map[string][]interface{}{ - "mojang_textures:usernames:after_call": {"username", &mojang.ProfileInfo{}, nil}, + Events: [][]interface{}{ + {"mojang_textures:usernames:after_call", "username", &mojang.ProfileInfo{}, nil}, }, ExpectedCalls: [][]interface{}{ {"IncCounter", "mock_prefix.mojang_textures.usernames.uuid_hit", int64(1)}, }, }, { - Events: map[string][]interface{}{ - "mojang_textures:textures:after_call": {"aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa", nil, errors.New("error")}, + Events: [][]interface{}{ + {"mojang_textures:textures:after_call", "aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa", nil, errors.New("error")}, }, ExpectedCalls: [][]interface{}{}, }, { - Events: map[string][]interface{}{ - "mojang_textures:textures:after_call": {"aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa", nil, nil}, + Events: [][]interface{}{ + {"mojang_textures:textures:after_call", "aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa", nil, nil}, }, ExpectedCalls: [][]interface{}{ {"IncCounter", "mock_prefix.mojang_textures.usernames.textures_miss", int64(1)}, }, }, { - Events: map[string][]interface{}{ - "mojang_textures:textures:after_call": {"aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa", &mojang.SignedTexturesResponse{}, nil}, + Events: [][]interface{}{ + {"mojang_textures:textures:after_call", "aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa", &mojang.SignedTexturesResponse{}, nil}, }, ExpectedCalls: [][]interface{}{ {"IncCounter", "mock_prefix.mojang_textures.usernames.textures_hit", int64(1)}, }, }, { - Events: map[string][]interface{}{ - "mojang_textures:before_result": {"username", ""}, - "mojang_textures:after_result": {"username", &mojang.SignedTexturesResponse{}, nil}, + Events: [][]interface{}{ + {"mojang_textures:before_result", "username", ""}, + {"mojang_textures:after_result", "username", &mojang.SignedTexturesResponse{}, nil}, }, ExpectedCalls: [][]interface{}{ {"RecordTimer", "mock_prefix.mojang_textures.result_time", mock.AnythingOfType("time.Duration")}, }, }, { - Events: map[string][]interface{}{ - "mojang_textures:textures:before_call": {"аааааааааааааааааааааааааааааааа"}, - "mojang_textures:textures:after_call": {"аааааааааааааааааааааааааааааааа", &mojang.SignedTexturesResponse{}, nil}, + Events: [][]interface{}{ + {"mojang_textures:textures:before_call", "аааааааааааааааааааааааааааааааа"}, + {"mojang_textures:textures:after_call", "аааааааааааааааааааааааааааааааа", &mojang.SignedTexturesResponse{}, nil}, }, ExpectedCalls: [][]interface{}{ {"IncCounter", "mock_prefix.mojang_textures.textures.request", int64(1)}, @@ -327,16 +327,16 @@ var statsReporterTestCases = []*StatsReporterTestCase{ }, // Batch UUIDs provider { - Events: map[string][]interface{}{ - "mojang_textures:batch_uuids_provider:queued": {"username"}, + Events: [][]interface{}{ + {"mojang_textures:batch_uuids_provider:queued", "username"}, }, ExpectedCalls: [][]interface{}{ {"IncCounter", "mock_prefix.mojang_textures.usernames.queued", int64(1)}, }, }, { - Events: map[string][]interface{}{ - "mojang_textures:batch_uuids_provider:round": {[]string{"username1", "username2"}, 5}, + Events: [][]interface{}{ + {"mojang_textures:batch_uuids_provider:round", []string{"username1", "username2"}, 5}, }, ExpectedCalls: [][]interface{}{ {"UpdateGauge", "mock_prefix.mojang_textures.usernames.iteration_size", int64(2)}, @@ -344,9 +344,9 @@ var statsReporterTestCases = []*StatsReporterTestCase{ }, }, { - Events: map[string][]interface{}{ - "mojang_textures:batch_uuids_provider:before_round": {}, - "mojang_textures:batch_uuids_provider:after_round": {}, + Events: [][]interface{}{ + {"mojang_textures:batch_uuids_provider:before_round"}, + {"mojang_textures:batch_uuids_provider:after_round"}, }, ExpectedCalls: [][]interface{}{ {"RecordTimer", "mock_prefix.mojang_textures.usernames.round_time", mock.AnythingOfType("time.Duration")}, @@ -366,14 +366,15 @@ func TestStatsReporter(t *testing.T) { } reporter := &StatsReporter{ - Reporter: statsReporterMock, - Prefix: "mock_prefix", + StatsReporter: statsReporterMock, + Prefix: "mock_prefix", } d := dispatcher.New() reporter.ConfigureWithDispatcher(d) - for event, args := range c.Events { - d.Emit(event, args...) + for _, e := range c.Events { + eventName, _ := e[0].(string) + d.Emit(eventName, e[1:]...) } statsReporterMock.AssertExpectations(t) From 767971a1978ca4693f82d06acac840a7cede9286 Mon Sep 17 00:00:00 2001 From: ErickSkrauch Date: Sat, 4 Apr 2020 00:28:50 +0300 Subject: [PATCH 15/18] Call mojang_textures:after_result event before broadcasting results to listeners --- mojangtextures/mojang_textures.go | 5 ++--- 1 file changed, 2 insertions(+), 3 deletions(-) diff --git a/mojangtextures/mojang_textures.go b/mojangtextures/mojang_textures.go index b04dd43..08885c3 100644 --- a/mojangtextures/mojang_textures.go +++ b/mojangtextures/mojang_textures.go @@ -124,11 +124,10 @@ func (ctx *Provider) GetForUsername(username string) (*mojang.SignedTexturesResp func (ctx *Provider) getResultAndBroadcast(username string, uuid string) { ctx.Emit("mojang_textures:before_result", username, uuid) - result := ctx.getResult(username, uuid) - ctx.broadcaster.BroadcastAndRemove(username, result) - ctx.Emit("mojang_textures:after_result", username, result.textures, result.error) + + ctx.broadcaster.BroadcastAndRemove(username, result) } func (ctx *Provider) getResult(username string, uuid string) *broadcastResult { From 0546b0519bd40246f3dd8bdcc3d3f5db1cc5aec8 Mon Sep 17 00:00:00 2001 From: ErickSkrauch Date: Sat, 4 Apr 2020 00:36:56 +0300 Subject: [PATCH 16/18] Do not send debug messages from logger event subscriber. Debug messages will be implemented later in a separate events' listener. --- eventsubscribers/logger.go | 2 -- eventsubscribers/logger_test.go | 6 +----- 2 files changed, 1 insertion(+), 7 deletions(-) diff --git a/eventsubscribers/logger.go b/eventsubscribers/logger.go index 357fa98..d9d34df 100644 --- a/eventsubscribers/logger.go +++ b/eventsubscribers/logger.go @@ -50,8 +50,6 @@ func (l *Logger) createMojangTexturesErrorHandler(provider string) func(identity errParam := wd.ErrParam(err) - l.Debug("Mojang "+provider+" provider resulted an error :err", errParam) - switch err.(type) { case *mojang.BadRequestError: l.logMojangTexturesWarning(providerParam, errParam) diff --git a/eventsubscribers/logger_test.go b/eventsubscribers/logger_test.go index e892234..83b5231 100644 --- a/eventsubscribers/logger_test.go +++ b/eventsubscribers/logger_test.go @@ -155,9 +155,7 @@ func init() { {"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")}, - }, + ExpectedCalls: nil, } loggerTestCases["should log expected mojang errors for "+pn+" provider"] = &LoggerTestCase{ @@ -170,7 +168,6 @@ func init() { {"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 { @@ -204,7 +201,6 @@ func init() { {"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 { From 2fbeb492f0ca3a63976e211a0f99eae691e4b727 Mon Sep 17 00:00:00 2001 From: ErickSkrauch Date: Sat, 4 Apr 2020 19:14:12 +0300 Subject: [PATCH 17/18] Initialize subscribers on app bootstrapping --- bootstrap/bootstrap.go | 34 ++++++------ cmd/serve.go | 43 ++++++++++----- cmd/worker.go | 30 ++++++++--- eventsubscribers/stats_reporter.go | 42 +++++---------- eventsubscribers/stats_reporter_test.go | 72 ++++++++++++------------- 5 files changed, 119 insertions(+), 102 deletions(-) diff --git a/bootstrap/bootstrap.go b/bootstrap/bootstrap.go index b93f540..9295b28 100644 --- a/bootstrap/bootstrap.go +++ b/bootstrap/bootstrap.go @@ -6,6 +6,7 @@ import ( "time" "github.com/getsentry/raven-go" + "github.com/mono83/slf" "github.com/mono83/slf/rays" "github.com/mono83/slf/recievers/sentry" "github.com/mono83/slf/recievers/statsd" @@ -19,27 +20,12 @@ import ( "github.com/elyby/chrly/version" ) -func CreateLogger(statsdAddr string, sentryAddr string) (wd.Watchdog, error) { +func CreateLogger(sentryAddr string) (slf.Logger, error) { wd.AddReceiver(writer.New(writer.Options{ Marker: false, TimeFormat: "15:04:05.000", })) - if statsdAddr != "" { - hostname, _ := os.Hostname() - statsdReceiver, err := statsd.NewReceiver(statsd.Config{ - Address: statsdAddr, - Prefix: "ely.skinsystem." + hostname + ".app.", - FlushEvery: 1, - }) - - if err != nil { - return nil, err - } - - wd.AddReceiver(statsdReceiver) - } - if sentryAddr != "" { ravenClient, err := raven.New(sentryAddr) if err != nil { @@ -66,6 +52,22 @@ func CreateLogger(statsdAddr string, sentryAddr string) (wd.Watchdog, error) { return wd.New("", "").WithParams(rays.Host), nil } +func CreateStatsReceiver(statsdAddr string) (slf.StatsReporter, error) { + hostname, _ := os.Hostname() + statsdReceiver, err := statsd.NewReceiver(statsd.Config{ + Address: statsdAddr, + Prefix: "ely.skinsystem." + hostname + ".app.", + FlushEvery: 1, + }) + if err != nil { + return nil, err + } + + wd.AddReceiver(statsdReceiver) + + return wd.New("", "").WithParams(rays.Host), nil +} + func init() { viper.SetDefault("queue.loop_delay", 2*time.Second+500*time.Millisecond) viper.SetDefault("queue.batch_size", 10) diff --git a/cmd/serve.go b/cmd/serve.go index 31d0680..425f758 100644 --- a/cmd/serve.go +++ b/cmd/serve.go @@ -3,6 +3,7 @@ package cmd import ( "fmt" "log" + "os" "github.com/mono83/slf/wd" "github.com/spf13/cobra" @@ -10,6 +11,7 @@ import ( "github.com/elyby/chrly/bootstrap" "github.com/elyby/chrly/db" + "github.com/elyby/chrly/eventsubscribers" "github.com/elyby/chrly/http" "github.com/elyby/chrly/mojangtextures" ) @@ -18,14 +20,27 @@ var serveCmd = &cobra.Command{ Use: "serve", Short: "Starts HTTP handler for the skins system", Run: func(cmd *cobra.Command, args []string) { + dispatcher := bootstrap.CreateEventDispatcher() + // TODO: this is a mess, need to organize this code somehow to make services initialization more compact - logger, err := bootstrap.CreateLogger(viper.GetString("statsd.addr"), viper.GetString("sentry.dsn")) + logger, err := bootstrap.CreateLogger(viper.GetString("sentry.dsn")) if err != nil { - log.Fatal(fmt.Printf("Cannot initialize logger: %v", err)) + log.Fatalf("Cannot initialize logger: %v", err) } logger.Info("Logger successfully initialized") - dispatcher := bootstrap.CreateEventDispatcher() + (&eventsubscribers.Logger{Logger: logger}).ConfigureWithDispatcher(dispatcher) + + statsdAddr := viper.GetString("statsd.addr") + if statsdAddr != "" { + statsdReporter, err := bootstrap.CreateStatsReceiver(statsdAddr) + if err != nil { + logger.Emergency("Invalid statsd configuration :err", wd.ErrParam(err)) + os.Exit(1) + } + + (&eventsubscribers.StatsReporter{StatsReporter: statsdReporter}).ConfigureWithDispatcher(dispatcher) + } storageFactory := db.StorageFactory{Config: viper.GetViper()} @@ -33,8 +48,8 @@ var serveCmd = &cobra.Command{ redisFactory := storageFactory.CreateFactory("redis") skinsRepo, err := redisFactory.CreateSkinsRepository() if err != nil { - logger.Emergency(fmt.Sprintf("Error on creating skins repo: %+v", err)) - return + logger.Emergency("Error on creating skins repo: :err", wd.ErrParam(err)) + os.Exit(1) } logger.Info("Skins repository successfully initialized") @@ -42,28 +57,28 @@ var serveCmd = &cobra.Command{ filesystemFactory := storageFactory.CreateFactory("filesystem") capesRepo, err := filesystemFactory.CreateCapesRepository() if err != nil { - logger.Emergency(fmt.Sprintf("Error on creating capes repo: %v", err)) - return + logger.Emergency("Error on creating capes repo: :err", wd.ErrParam(err)) + os.Exit(1) } logger.Info("Capes repository successfully initialized") logger.Info("Preparing Mojang's textures queue") mojangUuidsRepository, err := redisFactory.CreateMojangUuidsRepository() if err != nil { - logger.Emergency(fmt.Sprintf("Error on creating mojang uuids repo: %v", err)) - return + logger.Emergency("Error on creating mojang uuids repo: :err", wd.ErrParam(err)) + os.Exit(1) } uuidsProvider, err := bootstrap.CreateMojangUUIDsProvider(dispatcher) if err != nil { logger.Emergency("Unable to parse remote url :err", wd.ErrParam(err)) - return + os.Exit(1) } texturesStorage := mojangtextures.NewInMemoryTexturesStorage() texturesStorage.Start() mojangTexturesProvider := &mojangtextures.Provider{ - Emitter: dispatcher, + Emitter: dispatcher, UUIDsProvider: uuidsProvider, TexturesProvider: &mojangtextures.MojangApiTexturesProvider{ Emitter: dispatcher, @@ -88,16 +103,16 @@ var serveCmd = &cobra.Command{ finishChan := make(chan bool) go func() { - logger.Info(fmt.Sprintf("Starting the app, HTTP on: %s", address)) + logger.Info("Starting the app, HTTP on: :addr", wd.StringParam("addr", address)) if err := http.Serve(address, handler); err != nil { - logger.Error(fmt.Sprintf("Error in main(): %v", err)) + logger.Emergency("Error in main(): :err", wd.ErrParam(err)) finishChan <- true } }() go func() { s := waitForExitSignal() - logger.Info(fmt.Sprintf("Got signal: %v, exiting.", s)) + logger.Info("Got signal: :signal, exiting", wd.StringParam("signal", s.String())) finishChan <- true }() diff --git a/cmd/worker.go b/cmd/worker.go index 53b9f61..c383516 100644 --- a/cmd/worker.go +++ b/cmd/worker.go @@ -3,12 +3,14 @@ package cmd import ( "fmt" "log" + "os" "github.com/mono83/slf/wd" "github.com/spf13/cobra" "github.com/spf13/viper" "github.com/elyby/chrly/bootstrap" + "github.com/elyby/chrly/eventsubscribers" "github.com/elyby/chrly/http" ) @@ -16,18 +18,32 @@ var workerCmd = &cobra.Command{ Use: "worker", Short: "Starts HTTP handler for the Mojang usernames to UUIDs worker", Run: func(cmd *cobra.Command, args []string) { - logger, err := bootstrap.CreateLogger(viper.GetString("statsd.addr"), viper.GetString("sentry.dsn")) + dispatcher := bootstrap.CreateEventDispatcher() + + // TODO: need to find a way to unify this initialization with the serve command + logger, err := bootstrap.CreateLogger(viper.GetString("sentry.dsn")) if err != nil { - log.Fatal(fmt.Printf("Cannot initialize logger: %v", err)) + log.Fatalf("Cannot initialize logger: %v", err) } logger.Info("Logger successfully initialized") - dispatcher := bootstrap.CreateEventDispatcher() + (&eventsubscribers.Logger{Logger: logger}).ConfigureWithDispatcher(dispatcher) + + statsdAddr := viper.GetString("statsd.addr") + if statsdAddr != "" { + statsdReporter, err := bootstrap.CreateStatsReceiver(statsdAddr) + if err != nil { + logger.Emergency("Invalid statsd configuration :err", wd.ErrParam(err)) + os.Exit(1) + } + + (&eventsubscribers.StatsReporter{StatsReporter: statsdReporter}).ConfigureWithDispatcher(dispatcher) + } uuidsProvider, err := bootstrap.CreateMojangUUIDsProvider(dispatcher) if err != nil { logger.Emergency("Unable to parse remote url :err", wd.ErrParam(err)) - return + os.Exit(1) } address := fmt.Sprintf("%s:%d", viper.GetString("server.host"), viper.GetInt("server.port")) @@ -38,16 +54,16 @@ var workerCmd = &cobra.Command{ finishChan := make(chan bool) go func() { - logger.Info(fmt.Sprintf("Starting the worker, HTTP on: %s", address)) + logger.Info("Starting the worker, HTTP on: :addr", wd.StringParam("addr", address)) if err := http.Serve(address, handler); err != nil { - logger.Error(fmt.Sprintf("Error in main(): %v", err)) + logger.Error("Error in main(): :err", wd.ErrParam(err)) finishChan <- true } }() go func() { s := waitForExitSignal() - logger.Info(fmt.Sprintf("Got signal: %v, exiting.", s)) + logger.Info("Got signal: :code, exiting.", wd.StringParam("code", s.String())) finishChan <- true }() diff --git a/eventsubscribers/stats_reporter.go b/eventsubscribers/stats_reporter.go index ca1c18d..849c644 100644 --- a/eventsubscribers/stats_reporter.go +++ b/eventsubscribers/stats_reporter.go @@ -40,9 +40,9 @@ func (s *StatsReporter) ConfigureWithDispatcher(d Subscriber) { } if uuid == "" { - s.incCounter("mojang_textures:usernames:cache_hit_nil") + s.IncCounter("mojang_textures:usernames:cache_hit_nil", 1) } else { - s.incCounter("mojang_textures:usernames:cache_hit") + s.IncCounter("mojang_textures:usernames:cache_hit", 1) } }) d.Subscribe("mojang_textures:textures:after_cache", func(uuid string, textures *mojang.SignedTexturesResponse, err error) { @@ -51,7 +51,7 @@ func (s *StatsReporter) ConfigureWithDispatcher(d Subscriber) { } if textures != nil { - s.incCounter("mojang_textures.textures.cache_hit") + s.IncCounter("mojang_textures.textures.cache_hit", 1) } }) d.Subscribe("mojang_textures:already_processing", s.incCounterHandler("mojang_textures.already_scheduled")) @@ -61,9 +61,9 @@ func (s *StatsReporter) ConfigureWithDispatcher(d Subscriber) { } if profile == nil { - s.incCounter("mojang_textures.usernames.uuid_miss") + s.IncCounter("mojang_textures.usernames.uuid_miss", 1) } else { - s.incCounter("mojang_textures.usernames.uuid_hit") + s.IncCounter("mojang_textures.usernames.uuid_hit", 1) } }) d.Subscribe("mojang_textures:textures:before_call", s.incCounterHandler("mojang_textures.textures.request")) @@ -73,9 +73,9 @@ func (s *StatsReporter) ConfigureWithDispatcher(d Subscriber) { } if textures == nil { - s.incCounter("mojang_textures.usernames.textures_miss") + s.IncCounter("mojang_textures.usernames.textures_miss", 1) } else { - s.incCounter("mojang_textures.usernames.textures_hit") + s.IncCounter("mojang_textures.usernames.textures_hit", 1) } }) d.Subscribe("mojang_textures:before_result", func(username string, uuid string) { @@ -94,8 +94,8 @@ func (s *StatsReporter) ConfigureWithDispatcher(d Subscriber) { // Mojang UUIDs batch provider metrics d.Subscribe("mojang_textures:batch_uuids_provider:queued", s.incCounterHandler("mojang_textures.usernames.queued")) d.Subscribe("mojang_textures:batch_uuids_provider:round", func(usernames []string, queueSize int) { - s.updateGauge("mojang_textures.usernames.iteration_size", int64(len(usernames))) - s.updateGauge("mojang_textures.usernames.queue_size", int64(queueSize)) + s.UpdateGauge("mojang_textures.usernames.iteration_size", int64(len(usernames))) + s.UpdateGauge("mojang_textures.usernames.queue_size", int64(queueSize)) }) d.Subscribe("mojang_textures:batch_uuids_provider:before_round", func() { s.startTimeRecording("batch_uuids_provider_round_time") @@ -129,7 +129,7 @@ func (s *StatsReporter) handleBeforeRequest(req *http.Request) { return } - s.incCounter(key) + s.IncCounter(key, 1) } func (s *StatsReporter) handleAfterRequest(req *http.Request, code int) { @@ -148,12 +148,12 @@ func (s *StatsReporter) handleAfterRequest(req *http.Request, code int) { return } - s.incCounter(key) + s.IncCounter(key, 1) } func (s *StatsReporter) incCounterHandler(name string) func(...interface{}) { return func(...interface{}) { - s.incCounter(name) + s.IncCounter(name, 1) } } @@ -173,21 +173,5 @@ func (s *StatsReporter) finalizeTimeRecording(timeKey string, statName string) { delete(s.timersMap, timeKey) - s.recordTimer(statName, time.Since(startedAt)) -} - -func (s *StatsReporter) incCounter(name string) { - s.IncCounter(s.key(name), 1) -} - -func (s *StatsReporter) updateGauge(name string, value int64) { - s.UpdateGauge(s.key(name), value) -} - -func (s *StatsReporter) recordTimer(name string, duration time.Duration) { - s.RecordTimer(s.key(name), duration) -} - -func (s *StatsReporter) key(name string) string { - return strings.Join([]string{s.Prefix, name}, ".") + s.RecordTimer(statName, time.Since(startedAt)) } diff --git a/eventsubscribers/stats_reporter_test.go b/eventsubscribers/stats_reporter_test.go index a8ff3c5..448bafc 100644 --- a/eventsubscribers/stats_reporter_test.go +++ b/eventsubscribers/stats_reporter_test.go @@ -55,7 +55,7 @@ var statsReporterTestCases = []*StatsReporterTestCase{ {"skinsystem:before_request", httptest.NewRequest("GET", "http://localhost/skins/username", nil)}, }, ExpectedCalls: [][]interface{}{ - {"IncCounter", "mock_prefix.skins.request", int64(1)}, + {"IncCounter", "skins.request", int64(1)}, }, }, { @@ -63,7 +63,7 @@ var statsReporterTestCases = []*StatsReporterTestCase{ {"skinsystem:before_request", httptest.NewRequest("GET", "http://localhost/skins?name=username", nil)}, }, ExpectedCalls: [][]interface{}{ - {"IncCounter", "mock_prefix.skins.get_request", int64(1)}, + {"IncCounter", "skins.get_request", int64(1)}, }, }, { @@ -71,7 +71,7 @@ var statsReporterTestCases = []*StatsReporterTestCase{ {"skinsystem:before_request", httptest.NewRequest("GET", "http://localhost/cloaks/username", nil)}, }, ExpectedCalls: [][]interface{}{ - {"IncCounter", "mock_prefix.capes.request", int64(1)}, + {"IncCounter", "capes.request", int64(1)}, }, }, { @@ -79,7 +79,7 @@ var statsReporterTestCases = []*StatsReporterTestCase{ {"skinsystem:before_request", httptest.NewRequest("GET", "http://localhost/cloaks?name=username", nil)}, }, ExpectedCalls: [][]interface{}{ - {"IncCounter", "mock_prefix.capes.get_request", int64(1)}, + {"IncCounter", "capes.get_request", int64(1)}, }, }, { @@ -87,7 +87,7 @@ var statsReporterTestCases = []*StatsReporterTestCase{ {"skinsystem:before_request", httptest.NewRequest("GET", "http://localhost/textures/username", nil)}, }, ExpectedCalls: [][]interface{}{ - {"IncCounter", "mock_prefix.textures.request", int64(1)}, + {"IncCounter", "textures.request", int64(1)}, }, }, { @@ -95,7 +95,7 @@ var statsReporterTestCases = []*StatsReporterTestCase{ {"skinsystem:before_request", httptest.NewRequest("GET", "http://localhost/textures/signed/username", nil)}, }, ExpectedCalls: [][]interface{}{ - {"IncCounter", "mock_prefix.signed_textures.request", int64(1)}, + {"IncCounter", "signed_textures.request", int64(1)}, }, }, { @@ -103,7 +103,7 @@ var statsReporterTestCases = []*StatsReporterTestCase{ {"skinsystem:before_request", httptest.NewRequest("POST", "http://localhost/api/skins", nil)}, }, ExpectedCalls: [][]interface{}{ - {"IncCounter", "mock_prefix.api.skins.post.request", int64(1)}, + {"IncCounter", "api.skins.post.request", int64(1)}, }, }, { @@ -111,7 +111,7 @@ var statsReporterTestCases = []*StatsReporterTestCase{ {"skinsystem:before_request", httptest.NewRequest("DELETE", "http://localhost/api/skins/username", nil)}, }, ExpectedCalls: [][]interface{}{ - {"IncCounter", "mock_prefix.api.skins.delete.request", int64(1)}, + {"IncCounter", "api.skins.delete.request", int64(1)}, }, }, { @@ -119,7 +119,7 @@ var statsReporterTestCases = []*StatsReporterTestCase{ {"skinsystem:before_request", httptest.NewRequest("DELETE", "http://localhost/api/skins/id:1", nil)}, }, ExpectedCalls: [][]interface{}{ - {"IncCounter", "mock_prefix.api.skins.delete.request", int64(1)}, + {"IncCounter", "api.skins.delete.request", int64(1)}, }, }, { @@ -134,7 +134,7 @@ var statsReporterTestCases = []*StatsReporterTestCase{ {"skinsystem:after_request", httptest.NewRequest("POST", "http://localhost/api/skins", nil), 201}, }, ExpectedCalls: [][]interface{}{ - {"IncCounter", "mock_prefix.api.skins.post.success", int64(1)}, + {"IncCounter", "api.skins.post.success", int64(1)}, }, }, { @@ -142,7 +142,7 @@ var statsReporterTestCases = []*StatsReporterTestCase{ {"skinsystem:after_request", httptest.NewRequest("POST", "http://localhost/api/skins", nil), 400}, }, ExpectedCalls: [][]interface{}{ - {"IncCounter", "mock_prefix.api.skins.post.validation_failed", int64(1)}, + {"IncCounter", "api.skins.post.validation_failed", int64(1)}, }, }, { @@ -150,7 +150,7 @@ var statsReporterTestCases = []*StatsReporterTestCase{ {"skinsystem:after_request", httptest.NewRequest("DELETE", "http://localhost/api/skins/username", nil), 204}, }, ExpectedCalls: [][]interface{}{ - {"IncCounter", "mock_prefix.api.skins.delete.success", int64(1)}, + {"IncCounter", "api.skins.delete.success", int64(1)}, }, }, { @@ -158,7 +158,7 @@ var statsReporterTestCases = []*StatsReporterTestCase{ {"skinsystem:after_request", httptest.NewRequest("DELETE", "http://localhost/api/skins/username", nil), 404}, }, ExpectedCalls: [][]interface{}{ - {"IncCounter", "mock_prefix.api.skins.delete.not_found", int64(1)}, + {"IncCounter", "api.skins.delete.not_found", int64(1)}, }, }, { @@ -166,7 +166,7 @@ var statsReporterTestCases = []*StatsReporterTestCase{ {"skinsystem:after_request", httptest.NewRequest("DELETE", "http://localhost/api/skins/id:1", nil), 204}, }, ExpectedCalls: [][]interface{}{ - {"IncCounter", "mock_prefix.api.skins.delete.success", int64(1)}, + {"IncCounter", "api.skins.delete.success", int64(1)}, }, }, { @@ -174,7 +174,7 @@ var statsReporterTestCases = []*StatsReporterTestCase{ {"skinsystem:after_request", httptest.NewRequest("DELETE", "http://localhost/api/skins/id:1", nil), 404}, }, ExpectedCalls: [][]interface{}{ - {"IncCounter", "mock_prefix.api.skins.delete.not_found", int64(1)}, + {"IncCounter", "api.skins.delete.not_found", int64(1)}, }, }, { @@ -189,8 +189,8 @@ var statsReporterTestCases = []*StatsReporterTestCase{ {"authenticator:success"}, }, ExpectedCalls: [][]interface{}{ - {"IncCounter", "mock_prefix.authentication.challenge", int64(1)}, - {"IncCounter", "mock_prefix.authentication.success", int64(1)}, + {"IncCounter", "authentication.challenge", int64(1)}, + {"IncCounter", "authentication.success", int64(1)}, }, }, { @@ -198,8 +198,8 @@ var statsReporterTestCases = []*StatsReporterTestCase{ {"authentication:error", errors.New("error")}, }, ExpectedCalls: [][]interface{}{ - {"IncCounter", "mock_prefix.authentication.challenge", int64(1)}, - {"IncCounter", "mock_prefix.authentication.failed", int64(1)}, + {"IncCounter", "authentication.challenge", int64(1)}, + {"IncCounter", "authentication.failed", int64(1)}, }, }, // Mojang signed textures provider @@ -208,7 +208,7 @@ var statsReporterTestCases = []*StatsReporterTestCase{ {"mojang_textures:call", "username"}, }, ExpectedCalls: [][]interface{}{ - {"IncCounter", "mock_prefix.mojang_textures.request", int64(1)}, + {"IncCounter", "mojang_textures.request", int64(1)}, }, }, { @@ -222,7 +222,7 @@ var statsReporterTestCases = []*StatsReporterTestCase{ {"mojang_textures:usernames:after_cache", "username", "", nil}, }, ExpectedCalls: [][]interface{}{ - {"IncCounter", "mock_prefix.mojang_textures:usernames:cache_hit_nil", int64(1)}, + {"IncCounter", "mojang_textures:usernames:cache_hit_nil", int64(1)}, }, }, { @@ -230,7 +230,7 @@ var statsReporterTestCases = []*StatsReporterTestCase{ {"mojang_textures:usernames:after_cache", "username", "aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa", nil}, }, ExpectedCalls: [][]interface{}{ - {"IncCounter", "mock_prefix.mojang_textures:usernames:cache_hit", int64(1)}, + {"IncCounter", "mojang_textures:usernames:cache_hit", int64(1)}, }, }, { @@ -250,7 +250,7 @@ var statsReporterTestCases = []*StatsReporterTestCase{ {"mojang_textures:textures:after_cache", "aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa", &mojang.SignedTexturesResponse{}, nil}, }, ExpectedCalls: [][]interface{}{ - {"IncCounter", "mock_prefix.mojang_textures.textures.cache_hit", int64(1)}, + {"IncCounter", "mojang_textures.textures.cache_hit", int64(1)}, }, }, { @@ -258,7 +258,7 @@ var statsReporterTestCases = []*StatsReporterTestCase{ {"mojang_textures:already_processing", "username"}, }, ExpectedCalls: [][]interface{}{ - {"IncCounter", "mock_prefix.mojang_textures.already_scheduled", int64(1)}, + {"IncCounter", "mojang_textures.already_scheduled", int64(1)}, }, }, { @@ -272,7 +272,7 @@ var statsReporterTestCases = []*StatsReporterTestCase{ {"mojang_textures:usernames:after_call", "username", nil, nil}, }, ExpectedCalls: [][]interface{}{ - {"IncCounter", "mock_prefix.mojang_textures.usernames.uuid_miss", int64(1)}, + {"IncCounter", "mojang_textures.usernames.uuid_miss", int64(1)}, }, }, { @@ -280,7 +280,7 @@ var statsReporterTestCases = []*StatsReporterTestCase{ {"mojang_textures:usernames:after_call", "username", &mojang.ProfileInfo{}, nil}, }, ExpectedCalls: [][]interface{}{ - {"IncCounter", "mock_prefix.mojang_textures.usernames.uuid_hit", int64(1)}, + {"IncCounter", "mojang_textures.usernames.uuid_hit", int64(1)}, }, }, { @@ -294,7 +294,7 @@ var statsReporterTestCases = []*StatsReporterTestCase{ {"mojang_textures:textures:after_call", "aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa", nil, nil}, }, ExpectedCalls: [][]interface{}{ - {"IncCounter", "mock_prefix.mojang_textures.usernames.textures_miss", int64(1)}, + {"IncCounter", "mojang_textures.usernames.textures_miss", int64(1)}, }, }, { @@ -302,7 +302,7 @@ var statsReporterTestCases = []*StatsReporterTestCase{ {"mojang_textures:textures:after_call", "aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa", &mojang.SignedTexturesResponse{}, nil}, }, ExpectedCalls: [][]interface{}{ - {"IncCounter", "mock_prefix.mojang_textures.usernames.textures_hit", int64(1)}, + {"IncCounter", "mojang_textures.usernames.textures_hit", int64(1)}, }, }, { @@ -311,7 +311,7 @@ var statsReporterTestCases = []*StatsReporterTestCase{ {"mojang_textures:after_result", "username", &mojang.SignedTexturesResponse{}, nil}, }, ExpectedCalls: [][]interface{}{ - {"RecordTimer", "mock_prefix.mojang_textures.result_time", mock.AnythingOfType("time.Duration")}, + {"RecordTimer", "mojang_textures.result_time", mock.AnythingOfType("time.Duration")}, }, }, { @@ -320,9 +320,9 @@ var statsReporterTestCases = []*StatsReporterTestCase{ {"mojang_textures:textures:after_call", "аааааааааааааааааааааааааааааааа", &mojang.SignedTexturesResponse{}, nil}, }, ExpectedCalls: [][]interface{}{ - {"IncCounter", "mock_prefix.mojang_textures.textures.request", int64(1)}, - {"IncCounter", "mock_prefix.mojang_textures.usernames.textures_hit", int64(1)}, - {"RecordTimer", "mock_prefix.mojang_textures.textures.request_time", mock.AnythingOfType("time.Duration")}, + {"IncCounter", "mojang_textures.textures.request", int64(1)}, + {"IncCounter", "mojang_textures.usernames.textures_hit", int64(1)}, + {"RecordTimer", "mojang_textures.textures.request_time", mock.AnythingOfType("time.Duration")}, }, }, // Batch UUIDs provider @@ -331,7 +331,7 @@ var statsReporterTestCases = []*StatsReporterTestCase{ {"mojang_textures:batch_uuids_provider:queued", "username"}, }, ExpectedCalls: [][]interface{}{ - {"IncCounter", "mock_prefix.mojang_textures.usernames.queued", int64(1)}, + {"IncCounter", "mojang_textures.usernames.queued", int64(1)}, }, }, { @@ -339,8 +339,8 @@ var statsReporterTestCases = []*StatsReporterTestCase{ {"mojang_textures:batch_uuids_provider:round", []string{"username1", "username2"}, 5}, }, ExpectedCalls: [][]interface{}{ - {"UpdateGauge", "mock_prefix.mojang_textures.usernames.iteration_size", int64(2)}, - {"UpdateGauge", "mock_prefix.mojang_textures.usernames.queue_size", int64(5)}, + {"UpdateGauge", "mojang_textures.usernames.iteration_size", int64(2)}, + {"UpdateGauge", "mojang_textures.usernames.queue_size", int64(5)}, }, }, { @@ -349,7 +349,7 @@ var statsReporterTestCases = []*StatsReporterTestCase{ {"mojang_textures:batch_uuids_provider:after_round"}, }, ExpectedCalls: [][]interface{}{ - {"RecordTimer", "mock_prefix.mojang_textures.usernames.round_time", mock.AnythingOfType("time.Duration")}, + {"RecordTimer", "mojang_textures.usernames.round_time", mock.AnythingOfType("time.Duration")}, }, }, } From a459809b6b0026172118f0f8792a33caa50c99de Mon Sep 17 00:00:00 2001 From: ErickSkrauch Date: Mon, 6 Apr 2020 16:30:55 +0300 Subject: [PATCH 18/18] Update CHANGELOG --- CHANGELOG.md | 3 ++- 1 file changed, 2 insertions(+), 1 deletion(-) diff --git a/CHANGELOG.md b/CHANGELOG.md index a03a99d..419d9a3 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -18,11 +18,12 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0 username to its UUID. It can be used with some load balancing software to increase throughput of Mojang's textures proxy by splitting the load across multiple servers with its own IPs. - Textures extra param is now can be configured via `TEXTURES_EXTRA_PARAM_NAME` and `TEXTURES_EXTRA_PARAM_VALUE`. - - New StatsD metrics: - Counters: - `ely.skinsystem.{hostname}.app.mojang_textures.usernames.textures_hit` - `ely.skinsystem.{hostname}.app.mojang_textures.usernames.textures_miss` +- All incoming requests are now logging to the console in + [Apache Common Log Format](http://httpd.apache.org/docs/2.2/logs.html#common). ### Fixed - `ely.skinsystem.{hostname}.app.mojang_textures.usernames.iteration_size` and