Improve error handling and migrate to zerolog (#35)

Author: jaredledvina

client.go

@@ -4,11 +4,11 @@ import (
 	"context"
 	"errors"
 	"fmt"
-	"log"
 	"math"
 	"strings"
 
 	finnhub "github.com/Finnhub-Stock-API/finnhub-go/v2"
+	"github.com/rs/zerolog"
 	"github.com/seabird-chat/seabird-go"
 	"github.com/seabird-chat/seabird-go/pb"
 )
@@ -42,10 +42,11 @@ type SeabirdClient struct {
 	context.Context
 	*seabird.Client
 	finnhubClient *finnhub.DefaultApiService
+	logger        zerolog.Logger
 }
 
 // NewSeabirdClient returns a new seabird client
-func NewSeabirdClient(seabirdCoreURL, seabirdCoreToken, finnhubToken string) (*SeabirdClient, error) {
+func NewSeabirdClient(seabirdCoreURL, seabirdCoreToken, finnhubToken string, logger zerolog.Logger) (*SeabirdClient, error) {
 	seabirdClient, err := seabird.NewClient(seabirdCoreURL, seabirdCoreToken)
 	if err != nil {
 		return nil, err
@@ -58,27 +59,36 @@ func NewSeabirdClient(seabirdCoreURL, seabirdCoreToken, finnhubToken string) (*S
 		Context:       context.Background(),
 		Client:        seabirdClient,
 		finnhubClient: finnhub.NewAPIClient(finnhubCfg).DefaultApi,
+		logger:        logger,
 	}, nil
 }
 
 func (c *SeabirdClient) close() error {
 	return c.Client.Close()
 }
 
+func (c *SeabirdClient) reply(source *pb.ChannelSource, format string, args ...interface{}) {
+	if err := c.MentionReplyf(source, format, args...); err != nil {
+		c.logger.Error().Err(err).Str("channel_id", source.GetChannelId()).Msg("failed to send reply")
+	}
+}
+
 func (c *SeabirdClient) stockCallback(event *pb.CommandEvent) {
-	// TODO: Request debugging
-	log.Printf("Processing event: %s %s %s", event.Source, event.Command, event.Arg)
 	ticker := strings.ToUpper(strings.TrimSpace(event.Arg))
 
+	cmdLog := c.logger.With().
+		Str("command", event.Command).
+		Str("ticker", ticker).
+		Str("channel_id", event.Source.GetChannelId()).
+		Logger()
+
 	profile2, _, err := c.finnhubClient.CompanyProfile2(c.Context).Symbol(ticker).Execute()
 	if err != nil {
-		// TODO: What do we do with the error?
-		log.Println(err)
+		cmdLog.Error().Err(err).Msg("finnhub CompanyProfile2 failed")
+		c.reply(event.Source, "Unable to look up %s.", ticker)
 		return
 	}
 
-	log.Printf("profile2 is: %+v\n", profile2)
-
 	// If Finnhub fails to find ticker, we get a 200 back with empty values, so
 	// we set a default ticker/company and only use the profile response if it
 	// has valid values.
@@ -97,30 +107,31 @@ func (c *SeabirdClient) stockCallback(event *pb.CommandEvent) {
 	// only consistent way to determine if a stock actually exists.
 	if err != nil || quoteResp.ContentLength != -1 {
 		if err != nil {
-			log.Println(err)
+			cmdLog.Error().Err(err).Msg("finnhub Quote failed")
+			c.reply(event.Source, "Unable to fetch quote for %s.", ticker)
 			return
 		}
-		c.MentionReplyf(event.Source, "Unable to find %s.", ticker)
-	} else {
-		// TODO: Don't hardcoded USD here - currency requires premium https://finnhub.io/docs/api#company-profile
-		if event.Command == "stonk" || event.Command == "stonks" {
-			stonks := "is STONKS ↗️"
-			sign := stonkReplacements["+"]
-			if *quote.C <= *quote.O {
-				stonks = "is NOT STONKS ↘️"
-				sign = stonkReplacements["-"]
-			}
-
-			current := stonkify(fmt.Sprintf("$%.2f", *quote.C))
-			change := stonkify(fmt.Sprintf("%.2f", math.Abs(float64(*quote.C)-float64(*quote.O))))
+		c.reply(event.Source, "Unable to find %s.", ticker)
+		return
+	}
 
-			c.MentionReplyf(event.Source, "%s %s. %s (%s%s)", company, stonks, current, sign, change)
-		} else {
-			percentChange := ((*quote.C - *quote.O) / *quote.O) * 100
-			c.MentionReplyf(event.Source, "%s - Open: $%.2f, Current: $%.2f (%+.2f%%)", company, *quote.O, *quote.C, percentChange)
+	// TODO: Don't hardcoded USD here - currency requires premium https://finnhub.io/docs/api#company-profile
+	if event.Command == "stonk" || event.Command == "stonks" {
+		stonks := "is STONKS ↗️"
+		sign := stonkReplacements["+"]
+		if *quote.C <= *quote.O {
+			stonks = "is NOT STONKS ↘️"
+			sign = stonkReplacements["-"]
 		}
-	}
 
+		current := stonkify(fmt.Sprintf("$%.2f", *quote.C))
+		change := stonkify(fmt.Sprintf("%.2f", math.Abs(float64(*quote.C)-float64(*quote.O))))
+
+		c.reply(event.Source, "%s %s. %s (%s%s)", company, stonks, current, sign, change)
+	} else {
+		percentChange := ((*quote.C - *quote.O) / *quote.O) * 100
+		c.reply(event.Source, "%s - Open: $%.2f, Current: $%.2f (%+.2f%%)", company, *quote.O, *quote.C, percentChange)
+	}
 }
 
 // Run runs
@@ -136,7 +147,8 @@ func (c *SeabirdClient) Run() error {
 		return err
 	}
 
-	defer events.Close()
+	c.logger.Info().Msg("event stream open")
+
 	for event := range events.C {
 		switch v := event.GetInner().(type) {
 		case *pb.Event_Command:
@@ -146,5 +158,9 @@ func (c *SeabirdClient) Run() error {
 			}
 		}
 	}
-	return errors.New("event stream closed")
+
+	if closeErr := events.Close(); closeErr != nil {
+		return fmt.Errorf("event stream closed: %w", closeErr)
+	}
+	return errors.New("event stream closed without error")
 }

cmd/seabird-stock-plugin/main.go

@@ -1,7 +1,6 @@
 package main
 
 import (
-	"log"
 	"os"
 
 	stock "github.com/jaredledvina/seabird-stock-plugin"
@@ -23,29 +22,26 @@ func main() {
 	}
 
 	logger = logger.With().Timestamp().Logger()
-	logger.Level(zerolog.InfoLevel)
 
 	coreURL := os.Getenv("SEABIRD_HOST")
 	coreToken := os.Getenv("SEABIRD_TOKEN")
 	finnhubToken := os.Getenv("FINNHUB_TOKEN")
 
 	if coreURL == "" || coreToken == "" {
-		log.Fatal("Missing SEABIRD_HOST or SEABIRD_TOKEN")
+		logger.Fatal().Msg("Missing SEABIRD_HOST or SEABIRD_TOKEN")
 	}
 
 	if finnhubToken == "" {
-		log.Fatal("Missing FINNHUB_TOKEN")
+		logger.Fatal().Msg("Missing FINNHUB_TOKEN")
 	}
 
-	c, err := stock.NewSeabirdClient(coreURL, coreToken, finnhubToken)
+	c, err := stock.NewSeabirdClient(coreURL, coreToken, finnhubToken, logger)
 	if err != nil {
-		log.Fatalf("Failed to connect to seabird-core: %s", err)
+		logger.Fatal().Err(err).Msg("failed to dial seabird-core")
 	}
-	log.Printf("Successfully connected to seabird-core at %s", coreURL)
+	logger.Info().Str("host", coreURL).Msg("dialed seabird-core")
 
-	err = c.Run()
-	if err != nil {
-		log.Fatal(err)
+	if err := c.Run(); err != nil {
+		logger.Fatal().Err(err).Msg("event stream terminated")
 	}
-
 }