From 679b4136c8247f6f07da5e4daf3420e2e876f372 Mon Sep 17 00:00:00 2001 From: William Perron Date: Mon, 19 Sep 2022 12:28:07 +0000 Subject: [PATCH] Logging improvements * add zerolog and update existing log references * add log messages on operation failures Fixes #14 --- cmd/themis-server/main.go | 75 +++++++++++++++++++++------------------ go.mod | 5 ++- go.sum | 13 +++++++ 3 files changed, 57 insertions(+), 36 deletions(-) diff --git a/cmd/themis-server/main.go b/cmd/themis-server/main.go index 1d76311..87a0883 100644 --- a/cmd/themis-server/main.go +++ b/cmd/themis-server/main.go @@ -5,7 +5,6 @@ import ( "errors" "flag" "fmt" - "log" "net/http" "os" "os/signal" @@ -14,6 +13,7 @@ import ( "syscall" "github.com/bwmarrin/discordgo" + "github.com/rs/zerolog/log" "go.wperron.io/themis" ) @@ -38,37 +38,37 @@ func main() { err := touchDbFile(*dbFile) if err != nil { - log.Fatalln("fatal error: failed to touch database file:", err) + log.Fatal().Err(err).Msg("failed to touch database file") } connString := fmt.Sprintf(CONN_STRING_PATTERN, *dbFile) store, err = themis.NewStore(connString) if err != nil { - log.Fatalln("fatal error: failed to initialize database:", err) + log.Fatal().Err(err).Msg("failed to initialize database") } authToken, ok := os.LookupEnv("DISCORD_TOKEN") if !ok { - log.Fatalln("fatal error: no auth token found at DISCORD_TOKEN env var") + log.Fatal().Err(err).Msg("no auth token found at DISCORD_TOKEN env var") } appId, ok := os.LookupEnv("DISCORD_APP_ID") if !ok { - log.Fatalln("fatal error: no app id found at DISCORD_TOKEN env var") + log.Fatal().Err(err).Msg("no app id found at DISCORD_APP_ID env var") } guildId, ok := os.LookupEnv("DISCORD_GUILD_ID") if !ok { - log.Fatalln("fatal error: no guild id found at DISCORD_TOKEN env var") + log.Fatal().Err(err).Msg("no guild id found at DISCORD_GUILD_ID env var") } discord, err := discordgo.New(fmt.Sprintf("Bot %s", authToken)) if err != nil { - log.Fatalln("fatal error: failed to create discord app:", err) + log.Fatal().Err(err).Msg("failed to initialize discord session") } - log.Printf("connected to discord: app_id=%s, guild_id=%s\n", appId, guildId) + log.Info().Str("app_id", appId).Str("guild_id", guildId).Msg("connected to discord") commands := []*discordgo.ApplicationCommand{ { @@ -143,12 +143,13 @@ func main() { }, }) if err != nil { - log.Println("[error] failed to respond to command:", err) + log.Error().Err(err).Msg("failed to respond to interaction") } }, "list-claims": func(s *discordgo.Session, i *discordgo.InteractionCreate) { claims, err := store.ListClaims(ctx) if err != nil { + log.Error().Err(err).Msg("failed to list claims") err := s.InteractionRespond(i.Interaction, &discordgo.InteractionResponse{ Type: discordgo.InteractionResponseChannelMessageWithSource, Data: &discordgo.InteractionResponseData{ @@ -156,7 +157,7 @@ func main() { }, }) if err != nil { - log.Println("[error] failed to respond to command:", err) + log.Error().Err(err).Msg("failed to respond to interaction") } } @@ -173,7 +174,7 @@ func main() { }, }) if err != nil { - log.Println("[error] failed to respond to command:", err) + log.Error().Err(err).Msg("failed to respond to interaction") } }, "claim": func(s *discordgo.Session, i *discordgo.InteractionCreate) { @@ -191,13 +192,14 @@ func main() { }, }) if err != nil { - log.Println("[error] failed to respond to command:", err) + log.Error().Err(err).Msg("failed to respond to interaction") } return } claimType, err := themis.ClaimTypeFromString(opts[0].StringValue()) if err != nil { + log.Error().Err(err).Str("claim_type", opts[0].StringValue()).Msg("failed to parse claim") err = s.InteractionRespond(i.Interaction, &discordgo.InteractionResponse{ Type: discordgo.InteractionResponseChannelMessageWithSource, Data: &discordgo.InteractionResponseData{ @@ -205,7 +207,7 @@ func main() { }, }) if err != nil { - log.Println("[error] failed to respond to command:", err) + log.Error().Err(err).Msg("failed to respond to interaction") } return } @@ -236,11 +238,12 @@ func main() { }, }) if err != nil { - log.Println("[error] failed to respond to command:", err) + log.Error().Err(err).Msg("failed to respond to interaction") } return } - fmt.Printf("[error]: failed to acquire claim: %s\n", err) + + log.Error().Err(err).Msg("failed to acquire claim") err = s.InteractionRespond(i.Interaction, &discordgo.InteractionResponse{ Type: discordgo.InteractionResponseChannelMessageWithSource, Data: &discordgo.InteractionResponseData{ @@ -248,7 +251,7 @@ func main() { }, }) if err != nil { - log.Println("[error] failed to respond to command:", err) + log.Error().Err(err).Msg("failed to respond to interaction") } return } @@ -260,13 +263,14 @@ func main() { }, }) if err != nil { - log.Println("[error] failed to respond to command:", err) + log.Error().Err(err).Msg("failed to respond to interaction") } }, "describe-claim": func(s *discordgo.Session, i *discordgo.InteractionCreate) { id := i.ApplicationCommandData().Options[0] detail, err := store.DescribeClaim(ctx, int(id.IntValue())) if err != nil { + log.Error().Err(err).Msg("failed to describe claim") err = s.InteractionRespond(i.Interaction, &discordgo.InteractionResponse{ Type: discordgo.InteractionResponseChannelMessageWithSource, Data: &discordgo.InteractionResponseData{ @@ -274,7 +278,7 @@ func main() { }, }) if err != nil { - log.Println("[error] failed to respond to command:", err) + log.Error().Err(err).Msg("failed to respond to interaction") } } @@ -291,7 +295,7 @@ func main() { }, }) if err != nil { - log.Println("[error] failed to respond to command:", err) + log.Error().Err(err).Msg("failed to respond to interaction") } }, "delete-claim": func(s *discordgo.Session, i *discordgo.InteractionCreate) { @@ -303,7 +307,7 @@ func main() { if errors.Is(err, themis.ErrNoSuchClaim) { msg = fmt.Sprintf("Claim #%d not found for %s", id.IntValue(), i.Member.Nick) } - log.Printf("[error]: %s\n", err) + log.Error().Err(err).Msg("failed to delete claim") err = s.InteractionRespond(i.Interaction, &discordgo.InteractionResponse{ Type: discordgo.InteractionResponseChannelMessageWithSource, Data: &discordgo.InteractionResponseData{ @@ -311,7 +315,7 @@ func main() { }, }) if err != nil { - log.Println("[error] failed to respond to command:", err) + log.Error().Err(err).Msg("failed to respond to interaction") } } @@ -322,7 +326,7 @@ func main() { }, }) if err != nil { - log.Println("[error] failed to respond to command:", err) + log.Error().Err(err).Msg("failed to respond to interaction") } }, "flush": func(s *discordgo.Session, i *discordgo.InteractionCreate) { @@ -349,7 +353,7 @@ func main() { }, }, }); err != nil { - log.Println("failed to respond to command:", err) + log.Error().Err(err).Msg("failed to respond to interaction") } }, } @@ -358,7 +362,7 @@ func main() { err = discord.Open() if err != nil { - log.Fatalln("fatal error: failed to open session:", err) + log.Fatal().Err(err).Msg("failed to open discord websocket") } defer discord.Close() @@ -366,16 +370,16 @@ func main() { for i, c := range commands { command, err := discord.ApplicationCommandCreate(appId, guildId, c) if err != nil { - log.Fatalln("fatal error: failed to register command:", err) + log.Fatal().Err(err).Msg("failed to register command") } registeredCommands[i] = command } - log.Printf("registered %d commands\n", len(registeredCommands)) + log.Info().Int("count", len(registeredCommands)).Msg("registered commands") go func() { if err := serve(":8080"); err != nil { - log.Printf("[error]: %s\n", err) + log.Error().Err(err).Msg("failed to serve requests") } cancel() }() @@ -385,10 +389,10 @@ func main() { for _, c := range registeredCommands { err = discord.ApplicationCommandDelete(appId, guildId, c.ID) if err != nil { - log.Printf("[error]: failed to delete command: %s\n", err) + log.Error().Err(err).Msg("failed to deregister commands") } } - log.Println("deregistered commands, bye bye!") + log.Info().Msg("deregistered commands, exiting") os.Exit(0) } @@ -412,7 +416,7 @@ func touchDbFile(path string) error { func registerHandlers(sess *discordgo.Session, handlers map[string]Handler) { sess.AddHandler(func(s *discordgo.Session, r *discordgo.Ready) { - log.Printf("Logged in as: %v#%v", s.State.User.Username, s.State.User.Discriminator) + log.Info().Str("user_id", fmt.Sprintf("%s#%s", s.State.User.Username, s.State.User.Discriminator)).Msg("logged in") }) sess.AddHandler(func(s *discordgo.Session, i *discordgo.InteractionCreate) { switch i.Type { @@ -428,6 +432,7 @@ func registerHandlers(sess *discordgo.Session, handlers map[string]Handler) { err := store.Flush(context.Background()) msg := "Flushed all claims!" if err != nil { + log.Error().Err(err).Msg("failed to flush claims") msg = "failed to flush claims from database" } @@ -438,7 +443,7 @@ func registerHandlers(sess *discordgo.Session, handlers map[string]Handler) { }, }) if err != nil { - log.Println("[error] failed to respond to command:", err) + log.Error().Err(err).Msg("failed to respond to interaction") } return } @@ -450,7 +455,7 @@ func registerHandlers(sess *discordgo.Session, handlers map[string]Handler) { }, }) if err != nil { - log.Println("[error] failed to respond to command:", err) + log.Error().Err(err).Msg("failed to respond to interaction") } return } @@ -493,13 +498,13 @@ func handleClaimAutocomplete(ctx context.Context, store *themis.Store, s *discor opts := i.ApplicationCommandData().Options claimType, err := themis.ClaimTypeFromString(opts[0].StringValue()) if err != nil { - log.Printf("[error]: %s\n", err) + log.Error().Err(err).Msg("failed to parse claim type") return } availability, err := store.ListAvailability(ctx, claimType, opts[1].StringValue()) if err != nil { - log.Printf("[error]: %s\n", err) + log.Error().Err(err).Msg("failed to list availabilities") return } @@ -517,7 +522,7 @@ func handleClaimAutocomplete(ctx context.Context, store *themis.Store, s *discor Choices: choices[:min(len(choices), 25)], }, }); err != nil { - log.Printf("[error]: %s\n", err) + log.Error().Err(err).Msg("failed to respond to interaction") } } diff --git a/go.mod b/go.mod index 159e077..2f8592d 100644 --- a/go.mod +++ b/go.mod @@ -8,10 +8,13 @@ require ( github.com/bwmarrin/discordgo v0.26.1 // indirect github.com/davecgh/go-spew v1.1.1 // indirect github.com/gorilla/websocket v1.4.2 // indirect + github.com/mattn/go-colorable v0.1.12 // indirect + github.com/mattn/go-isatty v0.0.14 // indirect github.com/pmezard/go-difflib v1.0.0 // indirect + github.com/rs/zerolog v1.28.0 // indirect github.com/stretchr/objx v0.4.0 // indirect github.com/stretchr/testify v1.8.0 // indirect golang.org/x/crypto v0.0.0-20210421170649-83a5a9bb288b // indirect - golang.org/x/sys v0.0.0-20201119102817-f84b799fce68 // indirect + golang.org/x/sys v0.0.0-20210927094055-39ccf1dd6fa6 // indirect gopkg.in/yaml.v3 v3.0.1 // indirect ) diff --git a/go.sum b/go.sum index fc42333..ddc23d1 100644 --- a/go.sum +++ b/go.sum @@ -1,14 +1,24 @@ github.com/bwmarrin/discordgo v0.26.1 h1:AIrM+g3cl+iYBr4yBxCBp9tD9jR3K7upEjl0d89FRkE= github.com/bwmarrin/discordgo v0.26.1/go.mod h1:NJZpH+1AfhIcyQsPeuBKsUtYrRnjkyu0kIVMCHkZtRY= +github.com/coreos/go-systemd/v22 v22.3.3-0.20220203105225-a9a7ef127534/go.mod h1:Y58oyj3AT4RCenI/lSvhwexgC+NSVTIJ3seZv2GcEnc= github.com/davecgh/go-spew v1.1.0/go.mod h1:J7Y8YcW2NihsgmVo/mv3lAwl/skON4iLHjSsI+c5H38= github.com/davecgh/go-spew v1.1.1 h1:vj9j/u1bqnvCEfJOwUhtlOARqs3+rkHYY13jYWTU97c= github.com/davecgh/go-spew v1.1.1/go.mod h1:J7Y8YcW2NihsgmVo/mv3lAwl/skON4iLHjSsI+c5H38= +github.com/godbus/dbus/v5 v5.0.4/go.mod h1:xhWf0FNVPg57R7Z0UbKHbJfkEywrmjJnf7w5xrFpKfA= github.com/gorilla/websocket v1.4.2 h1:+/TMaTYc4QFitKJxsQ7Yye35DkWvkdLcvGKqM+x0Ufc= github.com/gorilla/websocket v1.4.2/go.mod h1:YR8l580nyteQvAITg2hZ9XVh4b55+EU/adAjf1fMHhE= +github.com/mattn/go-colorable v0.1.12 h1:jF+Du6AlPIjs2BiUiQlKOX0rt3SujHxPnksPKZbaA40= +github.com/mattn/go-colorable v0.1.12/go.mod h1:u5H1YNBxpqRaxsYJYSkiCWKzEfiAb1Gb520KVy5xxl4= +github.com/mattn/go-isatty v0.0.14 h1:yVuAays6BHfxijgZPzw+3Zlu5yQgKGP2/hcQbHb7S9Y= +github.com/mattn/go-isatty v0.0.14/go.mod h1:7GGIvUiUoEMVVmxf/4nioHXj79iQHKdU27kJ6hsGG94= github.com/mattn/go-sqlite3 v1.14.15 h1:vfoHhTN1af61xCRSWzFIWzx2YskyMTwHLrExkBOjvxI= github.com/mattn/go-sqlite3 v1.14.15/go.mod h1:2eHXhiwb8IkHr+BDWZGa96P6+rkvnG63S2DGjv9HUNg= +github.com/pkg/errors v0.9.1/go.mod h1:bwawxfHBFNV+L2hUp1rHADufV3IMtnDRdf1r5NINEl0= github.com/pmezard/go-difflib v1.0.0 h1:4DBwDE0NGyQoBHbLQYPwSUPoCMWR5BEzIk/f1lZbAQM= github.com/pmezard/go-difflib v1.0.0/go.mod h1:iKH77koFhYxTK1pcRnkKkqfTogsbg7gZNVY4sRDYZ/4= +github.com/rs/xid v1.4.0/go.mod h1:trrq9SKmegXys3aeAKXMUTdJsYXVwGY3RLcfgqegfbg= +github.com/rs/zerolog v1.28.0 h1:MirSo27VyNi7RJYP3078AA1+Cyzd2GB66qy3aUHvsWY= +github.com/rs/zerolog v1.28.0/go.mod h1:NILgTygv/Uej1ra5XxGf82ZFSLk58MFGAUS2o6usyD0= github.com/stretchr/objx v0.1.0/go.mod h1:HFkY916IF+rwdDfMAkV7OtwuqBVzrE8GR6GFx+wExME= github.com/stretchr/objx v0.4.0 h1:M2gUjqZET1qApGOWNSnZ49BAIMX4F/1plDv3+l31EJ4= github.com/stretchr/objx v0.4.0/go.mod h1:YvHI0jy2hoMjB+UWwv71VJQ9isScKT/TqJzVSSt89Yw= @@ -20,6 +30,9 @@ golang.org/x/crypto v0.0.0-20210421170649-83a5a9bb288b/go.mod h1:T9bdIzuCu7OtxOm golang.org/x/net v0.0.0-20210226172049-e18ecbb05110/go.mod h1:m0MpNAwzfU5UDzcl9v0D8zg8gWTRqZa9RBIspLL5mdg= golang.org/x/sys v0.0.0-20201119102817-f84b799fce68 h1:nxC68pudNYkKU6jWhgrqdreuFiOQWj1Fs7T3VrH4Pjw= golang.org/x/sys v0.0.0-20201119102817-f84b799fce68/go.mod h1:h1NjWce9XRLGQEsW7wpKNCjG9DtNlClVuFLEZdDNbEs= +golang.org/x/sys v0.0.0-20210630005230-0f9fa26af87c/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg= +golang.org/x/sys v0.0.0-20210927094055-39ccf1dd6fa6 h1:foEbQz/B0Oz6YIqu/69kfXPYeFQAuuMYFkjaqXzl5Wo= +golang.org/x/sys v0.0.0-20210927094055-39ccf1dd6fa6/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg= golang.org/x/term v0.0.0-20201126162022-7de9c90e9dd1/go.mod h1:bj7SfCRtBDWHUb9snDiAeCFNEtKQo2Wmx5Cou7ajbmo= golang.org/x/text v0.3.3/go.mod h1:5Zoc/QRtKVWzQhOtBMvqHzDpF6irO9z98xDceosuGiQ= golang.org/x/tools v0.0.0-20180917221912-90fa682c2a6e/go.mod h1:n7NCudcB/nEzxVGmLbDWY5pfWTLqBcC2KZ6jyYvM4mQ=