diff --git a/Gopkg.lock b/Gopkg.lock index cdc9b31..f974ee9 100644 --- a/Gopkg.lock +++ b/Gopkg.lock @@ -1,6 +1,12 @@ # This file is autogenerated, do not edit; changes may be undone by the next 'dep ensure'. +[[projects]] + name = "github.com/certifi/gocertifi" + packages = ["."] + revision = "3fd9e1adb12b72d2f3f82191d49be9b93c69f67c" + version = "2017.07.27" + [[projects]] name = "github.com/davecgh/go-spew" packages = ["spew"] @@ -13,6 +19,12 @@ revision = "629574ca2a5df945712d3079857300b5e4da0236" version = "v1.4.2" +[[projects]] + branch = "master" + name = "github.com/getsentry/raven-go" + packages = ["."] + revision = "d175f85701dfbf44cb0510114c9943e665e60907" + [[projects]] name = "github.com/golang/mock" packages = ["gomock"] @@ -35,7 +47,7 @@ branch = "master" name = "github.com/hashicorp/hcl" packages = [".","hcl/ast","hcl/parser","hcl/scanner","hcl/strconv","hcl/token","json/parser","json/scanner","json/token"] - revision = "392dba7d905ed5d04a5794ba89f558b27e2ba1ca" + revision = "8f6b1344a92ff8877cf24a5de9177bf7d0a2a187" [[projects]] name = "github.com/inconshreveable/mousetrap" @@ -53,7 +65,7 @@ branch = "master" name = "github.com/mediocregopher/radix.v2" packages = ["cluster","pool","redis","util"] - revision = "ae7309086d191442b36bf69f7f5eeca5fdbd329e" + revision = "0fe87e4a1bde3bb29991ea5ee1d9d536b77877d5" [[projects]] branch = "master" @@ -64,7 +76,7 @@ [[projects]] branch = "master" name = "github.com/mono83/slf" - packages = [".","params","rays","recievers","recievers/ansi","recievers/statsd","wd"] + packages = [".","filters","params","rays","recievers","recievers/ansi","recievers/statsd","wd"] revision = "8188a95c8d6b74c43953abb38b8bd6fdbc412ff5" [[projects]] @@ -95,7 +107,7 @@ branch = "master" name = "github.com/spf13/afero" packages = [".","mem"] - revision = "9be650865eab0c12963d8753212f4f9c66cdcf12" + revision = "36f8810e2e3d7eeac4ac05b57f65690fbfba62a2" [[projects]] name = "github.com/spf13/cast" @@ -107,7 +119,7 @@ branch = "master" name = "github.com/spf13/cobra" packages = ["."] - revision = "4a7b7e65864c064d48dce82efbbfed2bdc0bf2aa" + revision = "2df9a531813370438a4d79bfc33e21f58063ed87" [[projects]] branch = "master" @@ -143,13 +155,13 @@ branch = "master" name = "golang.org/x/sys" packages = ["unix"] - revision = "07c182904dbd53199946ba614a412c61d3c548f5" + revision = "2d6f6f883a06fc0d5f4b14a81e4c28705ea64c15" [[projects]] branch = "master" name = "golang.org/x/text" packages = ["internal/gen","internal/triegen","internal/ucd","transform","unicode/cldr","unicode/norm"] - revision = "e56139fd9c5bc7244c76116c68e500765bb6db6b" + revision = "ac87088df8ef557f1e32cd00ed0b6fbc3f7ddafb" [[projects]] name = "gopkg.in/h2non/gock.v1" @@ -166,6 +178,6 @@ [solve-meta] analyzer-name = "dep" analyzer-version = 1 - inputs-digest = "75c18193e3b7f0ae90987dc2e69a73c08c4329ab0ea3839112c05d45564d09c3" + inputs-digest = "fe0c38f46a10e79ddfd7449f98bcde02dbac62ec20cb9d957f661c6da079013f" solver-name = "gps-cdcl" solver-version = 1 diff --git a/Gopkg.toml b/Gopkg.toml index f23d8b2..b169acf 100644 --- a/Gopkg.toml +++ b/Gopkg.toml @@ -19,6 +19,9 @@ ignored = ["elyby/minecraft-skinsystem"] [[constraint]] name = "github.com/streadway/amqp" +[[constraint]] + name = "github.com/getsentry/raven-go" + # Testing dependencies [[constraint]] diff --git a/bootstrap/bootstrap.go b/bootstrap/bootstrap.go index 1c13c0e..0a35f1b 100644 --- a/bootstrap/bootstrap.go +++ b/bootstrap/bootstrap.go @@ -5,14 +5,17 @@ import ( "net/url" "os" + "github.com/getsentry/raven-go" "github.com/mono83/slf/rays" "github.com/mono83/slf/recievers/ansi" "github.com/mono83/slf/recievers/statsd" "github.com/mono83/slf/wd" "github.com/streadway/amqp" + + "elyby/minecraft-skinsystem/logger/receivers/sentry" ) -func CreateLogger(statsdAddr string) (wd.Watchdog, error) { +func CreateLogger(statsdAddr string, sentryAddr string) (wd.Watchdog, error) { wd.AddReceiver(ansi.New(true, true, false)) if statsdAddr != "" { hostname, _ := os.Hostname() @@ -29,6 +32,26 @@ func CreateLogger(statsdAddr string) (wd.Watchdog, error) { wd.AddReceiver(statsdReceiver) } + if sentryAddr != "" { + ravenClient, err := raven.New(sentryAddr) + if err != nil { + return nil, err + } + + ravenClient.SetRelease("1.3.2") // TODO: нужно как-то записывать версию во время билда + ravenClient.SetEnvironment("production") + ravenClient.SetDefaultLoggerName("sentry-watchdog-receiver") + + sentryReceiver, err := sentry.NewReceiverWithCustomRaven(ravenClient, &sentry.Config{ + MinLevel: "warn", + }) + if err != nil { + return nil, err + } + + wd.AddReceiver(sentryReceiver) + } + return wd.New("", "").WithParams(rays.Host), nil } diff --git a/cmd/amqpWorker.go b/cmd/amqpWorker.go index c2baea7..282c7ea 100644 --- a/cmd/amqpWorker.go +++ b/cmd/amqpWorker.go @@ -17,7 +17,7 @@ var amqpWorkerCmd = &cobra.Command{ Use: "amqp-worker", Short: "Launches a worker which listens to events and processes them", Run: func(cmd *cobra.Command, args []string) { - logger, err := bootstrap.CreateLogger(viper.GetString("statsd.addr")) + logger, err := bootstrap.CreateLogger(viper.GetString("statsd.addr"), viper.GetString("sentry.dsn")) if err != nil { log.Fatal(fmt.Printf("Cannot initialize logger: %v", err)) } diff --git a/cmd/serve.go b/cmd/serve.go index acc57a4..d67ef97 100644 --- a/cmd/serve.go +++ b/cmd/serve.go @@ -16,7 +16,7 @@ var serveCmd = &cobra.Command{ Use: "serve", Short: "Runs the system server skins", Run: func(cmd *cobra.Command, args []string) { - logger, err := bootstrap.CreateLogger(viper.GetString("statsd.addr")) + logger, err := bootstrap.CreateLogger(viper.GetString("statsd.addr"), viper.GetString("sentry.dsn")) if err != nil { log.Fatal(fmt.Printf("Cannot initialize logger: %v", err)) } diff --git a/logger/receivers/sentry/receiver.go b/logger/receivers/sentry/receiver.go new file mode 100644 index 0000000..9c0b872 --- /dev/null +++ b/logger/receivers/sentry/receiver.go @@ -0,0 +1,132 @@ +package sentry + +import ( + "fmt" + + "github.com/getsentry/raven-go" + "github.com/mono83/slf" + "github.com/mono83/slf/filters" +) + +// Config holds information for filtered receiver +type Config struct { + MinLevel string + ParamsWhiteList []string + ParamsBlackList []string +} + +// NewReceiver allows you to create a new receiver in the Sentry +// using the fastest and easiest way. +// The Config parameter can be passed as nil if you do not need additional filtration. +func NewReceiver(dsn string, cfg *Config) (slf.Receiver, error) { + client, err := raven.New(dsn) + if err != nil { + return nil, err + } + + return NewReceiverWithCustomRaven(client, cfg) +} + +// NewReceiverWithCustomRaven allows you to create a new receiver in the Sentry +// configuring raven.Client by yourself. This can be useful if you need to set +// additional parameters, such as release and environment, that will be sent +// with each Packet in the Sentry: +// +// client, err := raven.New("https://some:sentry@dsn.sentry.io/1") +// if err != nil { +// return nil, err +// } +// +// client.SetRelease("1.3.2") +// client.SetEnvironment("production") +// client.SetDefaultLoggerName("sentry-watchdog-receiver") +// +// sentryReceiver, err := sentry.NewReceiverWithCustomRaven(client, &sentry.Config{ +// MinLevel: "warn", +// }) +// +// The Config parameter allows you to add additional filtering, such as the minimum +// message level and the exclusion of private parameters. If you do not need additional +// filtering, nil can passed. +func NewReceiverWithCustomRaven(client *raven.Client, cfg *Config) (slf.Receiver, error) { + out, err := buildReceiverForClient(client) + if err != nil { + return nil, err + } + + if cfg == nil { + return out, nil + } + + // Resolving level + level, ok := slf.ParseType(cfg.MinLevel) + if !ok { + return nil, fmt.Errorf("Unknown level %s", cfg.MinLevel) + } + + if len(cfg.ParamsWhiteList) > 0 { + out.filter = slf.NewWhiteListParamsFilter(cfg.ParamsWhiteList) + } else { + out.filter = slf.NewBlackListParamsFilter(cfg.ParamsBlackList) + } + + return filters.MinLogLevel(level, out), nil +} + +func buildReceiverForClient(client *raven.Client) (*sentryLogReceiver, error) { + return &sentryLogReceiver{target: client, filter: slf.NewBlackListParamsFilter(nil)}, nil +} + +type sentryLogReceiver struct { + target *raven.Client + filter slf.ParamsFilter +} + +func (l sentryLogReceiver) Receive(p slf.Event) { + if !p.IsLog() { + return + } + + pkt := raven.NewPacket( + slf.ReplacePlaceholders(p.Content, p.Params, false), + // First 5 means, that first N elements will be skipped before actual app trace + // This is needed to exclude watchdog calls from stack trace + raven.NewStacktrace(5, 5, []string{}), + ) + + if len(p.Params) > 0 { + shownParams := l.filter(p.Params) + for _, param := range shownParams { + value := param.GetRaw() + if e, ok := value.(error); ok && e != nil { + value = e.Error() + } + + pkt.Extra[param.GetKey()] = value + } + } + + pkt.Level = convertType(p.Type) + pkt.Timestamp = raven.Timestamp(p.Time) + + l.target.Capture(pkt, map[string]string{}) +} + +func convertType(wdType byte) raven.Severity { + switch wdType { + case slf.TypeTrace: + case slf.TypeDebug: + return raven.DEBUG + case slf.TypeInfo: + return raven.INFO + case slf.TypeWarning: + return raven.WARNING + case slf.TypeError: + return raven.ERROR + case slf.TypeAlert: + case slf.TypeEmergency: + return raven.FATAL + } + + panic("Unknown wd type " + string(wdType)) +} diff --git a/worker/worder_test.go b/worker/worder_test.go index 5ac997d..a9f0a5e 100644 --- a/worker/worder_test.go +++ b/worker/worder_test.go @@ -1,6 +1,7 @@ package worker import ( + "errors" "testing" "github.com/golang/mock/gomock" @@ -52,6 +53,21 @@ func TestServices_HandleChangeUsername(t *testing.T) { skinRepo.EXPECT().Save(&model.Skin{UserId: 1, Username: "new_mock2"}) wd.EXPECT().IncCounter("worker.change_username", int64(1)) wd.EXPECT().IncCounter("worker.change_username_id_not_found", int64(1)) + wd.EXPECT().Info("Cannot find user id :accountId. Trying to search.", gomock.Any()) + + assert.True(services.HandleChangeUsername(&model.UsernameChanged{ + AccountId: 1, + OldUsername: "mock_user", + NewUsername: "new_mock2", + })) + + // Репозиторий вернул неожиданную ошибку + skinRepo.EXPECT().FindByUserId(1).Return(nil, errors.New("mock error")) + skinRepo.EXPECT().Save(&model.Skin{UserId: 1, Username: "new_mock2"}) + wd.EXPECT().IncCounter("worker.change_username", int64(1)) + wd.EXPECT().IncCounter("worker.change_username_id_not_found", int64(1)) + wd.EXPECT().Info("Cannot find user id :accountId. Trying to search.", gomock.Any()) + wd.EXPECT().Error("Unknown error when requesting a skin from the repository: :err", gomock.Any()) assert.True(services.HandleChangeUsername(&model.UsernameChanged{ AccountId: 1, @@ -109,8 +125,8 @@ func TestServices_HandleSkinChanged(t *testing.T) { wd.EXPECT().IncCounter("worker.skin_changed", int64(1)) wd.EXPECT().IncCounter("worker.skin_changed_id_not_found", int64(1)) wd.EXPECT().IncCounter("worker.skin_changed_id_restored", int64(1)) - wd.EXPECT().Warning(gomock.Any()) - wd.EXPECT().Info(gomock.Any()) + wd.EXPECT().Info("Cannot find user id :accountId. Trying to search.", gomock.Any()) + wd.EXPECT().Info("User info successfully restored.") assert.True(services.HandleSkinChanged(event)) @@ -120,8 +136,20 @@ func TestServices_HandleSkinChanged(t *testing.T) { wd.EXPECT().IncCounter("worker.skin_changed", int64(1)) wd.EXPECT().IncCounter("worker.skin_changed_id_not_found", int64(1)) wd.EXPECT().IncCounter("worker.skin_changed_id_not_restored", int64(1)) - wd.EXPECT().Warning(gomock.Any()) - wd.EXPECT().Error(gomock.Any()) + wd.EXPECT().Info("Cannot find user id :accountId. Trying to search.", gomock.Any()) + wd.EXPECT().Error("Cannot restore user info for :accountId: :err", gomock.Any(), gomock.Any()) + + assert.True(services.HandleSkinChanged(event)) + + // Репозиторий скинов вернул неизвестную ошибку, и Ely.by Accounts internal API не знает о таком пользователе + skinRepo.EXPECT().FindByUserId(1).Return(nil, errors.New("mocked error")) + accountsAPI.EXPECT().AccountInfo("id", "1").Return(nil, &accounts.NotFoundResponse{}) + wd.EXPECT().IncCounter("worker.skin_changed", int64(1)) + wd.EXPECT().IncCounter("worker.skin_changed_id_not_found", int64(1)) + wd.EXPECT().IncCounter("worker.skin_changed_id_not_restored", int64(1)) + wd.EXPECT().Error("Unknown error when requesting a skin from the repository: :err", gomock.Any()) + wd.EXPECT().Info("Cannot find user id :accountId. Trying to search.", gomock.Any()) + wd.EXPECT().Error("Cannot restore user info for :accountId: :err", gomock.Any(), gomock.Any()) assert.True(services.HandleSkinChanged(event)) } diff --git a/worker/worker.go b/worker/worker.go index 2260f46..b2d3eef 100644 --- a/worker/worker.go +++ b/worker/worker.go @@ -2,12 +2,12 @@ package worker import ( "encoding/json" - "fmt" "strconv" "github.com/mono83/slf/wd" "github.com/streadway/amqp" + "elyby/minecraft-skinsystem/db" "elyby/minecraft-skinsystem/interfaces" "elyby/minecraft-skinsystem/model" ) @@ -80,7 +80,11 @@ func (service *Services) HandleChangeUsername(event *model.UsernameChanged) bool record, err := service.SkinsRepo.FindByUserId(event.AccountId) if err != nil { - // TODO: если это не SkinNotFound, то нужно логгировать в Sentry + service.Logger.Info("Cannot find user id :accountId. Trying to search.", wd.IntParam("accountId", event.AccountId)) + if _, isSkinNotFound := err.(*db.SkinNotFoundError); !isSkinNotFound { + service.Logger.Error("Unknown error when requesting a skin from the repository: :err", wd.ErrParam(err)) + } + service.Logger.IncCounter("worker.change_username_id_not_found", 1) record = &model.Skin{ UserId: event.AccountId, @@ -99,13 +103,21 @@ func (service *Services) HandleSkinChanged(event *model.SkinChanged) bool { var record *model.Skin record, err := service.SkinsRepo.FindByUserId(event.AccountId) if err != nil { + if _, isSkinNotFound := err.(*db.SkinNotFoundError); !isSkinNotFound { + service.Logger.Error("Unknown error when requesting a skin from the repository: :err", wd.ErrParam(err)) + } + service.Logger.IncCounter("worker.skin_changed_id_not_found", 1) - service.Logger.Warning("Cannot find user id. Trying to search.") + service.Logger.Info("Cannot find user id :accountId. Trying to search.", wd.IntParam("accountId", event.AccountId)) response, err := service.AccountsAPI.AccountInfo("id", strconv.Itoa(event.AccountId)) if err != nil { service.Logger.IncCounter("worker.skin_changed_id_not_restored", 1) - service.Logger.Error(fmt.Sprintf("Cannot restore user info. %+v\n", err)) - // TODO: логгировать в какой-нибудь Sentry, если там не 404 + service.Logger.Error( + "Cannot restore user info for :accountId: :err", + wd.IntParam("accountId", event.AccountId), + wd.ErrParam(err), + ) + return true }