Add stack tracing to logger, use Stack on all fatal/error logs

2025-12-11 10:06:36 -06:00 · 2024-01-31 17:58:57 -06:00
parent 9344f1c365
commit 1252e75c8a
8 changed files with 45 additions and 41 deletions
--- a/api.go
+++ b/api.go
@@ -94,19 +94,19 @@ func SelectTerm(term string) {

 	res, err := DoRequest(req)
 	if err != nil {
-		log.Fatal().Err(err).Msg("Failed to select term")
+		log.Fatal().Stack().Err(err).Msg("Failed to select term")
 	}

 	// Assert that the response is JSON
 	if !ContentTypeMatch(res, "application/json") {
-		log.Fatal().Str("content-type", res.Header.Get("Content-Type")).Msg("Response was not JSON")
+		log.Fatal().Stack().Str("content-type", res.Header.Get("Content-Type")).Msg("Response was not JSON")
 	}

 	// Acquire fwdUrl
 	defer res.Body.Close()
 	body, err := io.ReadAll(res.Body)
 	if err != nil {
-		log.Fatal().Err(err).Msg("Failed to read response body")
+		log.Fatal().Stack().Err(err).Msg("Failed to read response body")
 	}

 	var redirectResponse struct {
@@ -118,12 +118,12 @@ func SelectTerm(term string) {
 	req = BuildRequest("GET", redirectResponse.FwdUrl, nil)
 	res, err = DoRequest(req)
 	if err != nil {
-		log.Fatal().Err(err).Msg("Redirect request failed")
+		log.Fatal().Stack().Err(err).Msg("Redirect request failed")
 	}

 	// Assert that the response is OK (200)
 	if res.StatusCode != 200 {
-		log.Fatal().Int("status", res.StatusCode).Msg("Unexpected status code from redirect request")
+		log.Fatal().Stack().Int("status", res.StatusCode).Msg("Unexpected status code from redirect request")
 	}
 }

@@ -151,7 +151,7 @@ func GetPartOfTerms(search string, term int, offset int, max int) ([]BannerTerm,

 	// Assert that the response is JSON
 	if !ContentTypeMatch(res, "application/json") {
-		log.Fatal().Str("content-type", res.Header.Get("Content-Type")).Msg("Response was not JSON")
+		log.Fatal().Stack().Str("content-type", res.Header.Get("Content-Type")).Msg("Response was not JSON")
 	}

 	defer res.Body.Close()
@@ -195,7 +195,7 @@ func GetInstructors(search string, term string, offset int, max int) ([]Instruct

 	// Assert that the response is JSON
 	if !ContentTypeMatch(res, "application/json") {
-		log.Fatal().Str("content-type", res.Header.Get("Content-Type")).Msg("Response was not JSON")
+		log.Fatal().Stack().Str("content-type", res.Header.Get("Content-Type")).Msg("Response was not JSON")
 	}

 	defer res.Body.Close()
@@ -225,7 +225,7 @@ func GetCourseDetails(term int, crn int) *ClassDetails {
 		"first":                 "first", // TODO: What is this?
 	})
 	if err != nil {
-		log.Fatal().Err(err).Msg("Failed to marshal body")
+		log.Fatal().Stack().Err(err).Msg("Failed to marshal body")
 	}
 	req := BuildRequestWithBody("GET", "/searchResults/getClassDetails", nil, bytes.NewBuffer(body))

@@ -236,7 +236,7 @@ func GetCourseDetails(term int, crn int) *ClassDetails {

 	// Assert that the response is JSON
 	if !ContentTypeMatch(res, "application/json") {
-		log.Fatal().Str("content-type", res.Header.Get("Content-Type")).Msg("Response was not JSON")
+		log.Fatal().Stack().Str("content-type", res.Header.Get("Content-Type")).Msg("Response was not JSON")
 	}

 	return &ClassDetails{}
@@ -266,7 +266,7 @@ func Search(query *Query, sort string, sortDescending bool) (*SearchResult, erro

 	// Assert that the response is JSON
 	if !ContentTypeMatch(res, "application/json") {
-		log.Error().Str("content-type", res.Header.Get("Content-Type")).Msg("Response was not JSON")
+		log.Error().Stack().Str("content-type", res.Header.Get("Content-Type")).Msg("Response was not JSON")
 	}

 	body, err := io.ReadAll(res.Body)
@@ -309,7 +309,7 @@ func GetSubjects(search string, term string, offset int, max int) ([]Pair, error

 	// Assert that the response is JSON
 	if !ContentTypeMatch(res, "application/json") {
-		log.Fatal().Str("content-type", res.Header.Get("Content-Type")).Msg("Response was not JSON")
+		log.Fatal().Stack().Str("content-type", res.Header.Get("Content-Type")).Msg("Response was not JSON")
 	}

 	defer res.Body.Close()
@@ -353,7 +353,7 @@ func GetCampuses(search string, term int, offset int, max int) ([]Pair, error) {

 	// Assert that the response is JSON
 	if !ContentTypeMatch(res, "application/json") {
-		log.Fatal().Str("content-type", res.Header.Get("Content-Type")).Msg("Response was not JSON")
+		log.Fatal().Stack().Str("content-type", res.Header.Get("Content-Type")).Msg("Response was not JSON")
 	}

 	defer res.Body.Close()
@@ -392,13 +392,12 @@ func GetInstructionalMethods(search string, term string, offset int, max int) ([

 	res, err := DoRequest(req)
 	if err != nil {
-		log.Err(err).Msg("Failed to get instructional methods")
 		return nil, fmt.Errorf("failed to get instructional methods: %w", err)
 	}

 	// Assert that the response is JSON
 	if !ContentTypeMatch(res, "application/json") {
-		log.Fatal().Str("content-type", res.Header.Get("Content-Type")).Msg("Response was not JSON")
+		log.Fatal().Stack().Str("content-type", res.Header.Get("Content-Type")).Msg("Response was not JSON")
 	}

 	defer res.Body.Close()
@@ -429,7 +428,7 @@ func GetCourseMeetingTime(term int, crn int) ([]MeetingTimeResponse, error) {

 	// Assert that the response is JSON
 	if !ContentTypeMatch(res, "application/json") {
-		log.Fatal().Str("content-type", res.Header.Get("Content-Type")).Msg("Response was not JSON")
+		log.Fatal().Stack().Str("content-type", res.Header.Get("Content-Type")).Msg("Response was not JSON")
 	}

 	// Read the response body into JSON
@@ -456,7 +455,7 @@ func ResetDataForm() {
 	req := BuildRequest("POST", "/classSearch/resetDataForm", nil)
 	_, err := DoRequest(req)
 	if err != nil {
-		log.Fatal().Err(err).Msg("Failed to reset data form")
+		log.Fatal().Stack().Err(err).Msg("Failed to reset data form")
 	}
 }

--- a/go.mod
+++ b/go.mod
@@ -13,6 +13,7 @@ require (
 	github.com/dgryski/go-rendezvous v0.0.0-20200823014737-9f7001d12a5f // indirect
 	github.com/mattn/go-colorable v0.1.13 // indirect
 	github.com/mattn/go-isatty v0.0.19 // indirect
+	github.com/pkg/errors v0.9.1 // indirect
 	github.com/redis/go-redis/v9 v9.3.1 // indirect
 	github.com/rs/zerolog v1.31.0 // indirect
 	github.com/samber/lo v1.39.0 // indirect
--- a/go.sum
+++ b/go.sum
@@ -39,6 +39,7 @@ github.com/mattn/go-isatty v0.0.16/go.mod h1:kYGgaQfpe5nmfYZH+SKPsOc2e4SrIfOl2e/
 github.com/mattn/go-isatty v0.0.19 h1:JITubQf0MOLdlGRuRq+jtsDlekdYPia9ZFsB8h/APPA=
 github.com/mattn/go-isatty v0.0.19/go.mod h1:W+V8PltTTMOvKvAeJH7IuucS94S2C6jfK/D7dTCTo3Y=
 github.com/niemeyer/pretty v0.0.0-20200227124842-a10e7caefd8e/go.mod h1:zD1mROLANZcx1PVRCS0qkT7pwLkGfwJo4zjcN/Tysno=
+github.com/pkg/errors v0.9.1 h1:FEBLx1zS214owpjy7qsBeixbURkuhQAwrK5UwLGTwt4=
 github.com/pkg/errors v0.9.1/go.mod h1:bwawxfHBFNV+L2hUp1rHADufV3IMtnDRdf1r5NINEl0=
 github.com/pmezard/go-difflib v1.0.0/go.mod h1:iKH77koFhYxTK1pcRnkKkqfTogsbg7gZNVY4sRDYZ/4=
 github.com/redis/go-redis v6.15.9+incompatible h1:F+tnlesQSl3h9V8DdmtcYFdvkHLhbb7AgcLW6UJxnC4=
--- a/helpers.go
+++ b/helpers.go
@@ -123,7 +123,7 @@ func DoRequest(req *http.Request) (*http.Response, error) {
 	res, err := client.Do(req)

 	if err != nil {
-		log.Err(err).Str("method", req.Method).Msg("Request Failed")
+		log.Err(err).Stack().Str("method", req.Method).Msg("Request Failed")
 	} else {
 		contentLengthHeader := res.Header.Get("Content-Length")
 		contentLength := int64(-1)
@@ -284,14 +284,14 @@ func DumpResponse(res *http.Response) {
 	file, err := os.Create(filename)

 	if err != nil {
-		log.Err(err).Msg("Error creating file")
+		log.Err(err).Stack().Msg("Error creating file")
 		return
 	}
 	defer file.Close()

 	_, err = io.Copy(file, res.Body)
 	if err != nil {
-		log.Err(err).Msg("Error copying response body")
+		log.Err(err).Stack().Msg("Error copying response body")
 		return
 	}

@@ -303,7 +303,7 @@ func DumpResponse(res *http.Response) {
 func RespondError(session *discordgo.Session, interaction *discordgo.Interaction, message string, err error) error {
 	// Optional: log the error
 	if err != nil {
-		log.Err(err).Msg(message)
+		log.Err(err).Stack().Msg(message)
 	}

 	return session.InteractionRespond(interaction, &discordgo.InteractionResponse{
--- a/main.go
+++ b/main.go
@@ -16,6 +16,7 @@ import (
 	"github.com/redis/go-redis/v9"
 	"github.com/rs/zerolog"
 	"github.com/rs/zerolog/log"
+	"github.com/rs/zerolog/pkgerrors"
 	"github.com/samber/lo"
 )

@@ -57,6 +58,8 @@ func init() {
 		return time.Now().In(CentralTimeLocation)
 	}

+	zerolog.ErrorStackMarshaler = pkgerrors.MarshalStack
+
 	// Try to grab the environment variable, or default to development
 	environment = GetFirstEnv("ENVIRONMENT", "RAILWAY_ENVIRONMENT")
 	if environment == "" {
@@ -82,13 +85,13 @@ func initRedis() {
 	// Setup redis
 	redisUrl := GetFirstEnv("REDIS_URL", "REDIS_PRIVATE_URL")
 	if redisUrl == "" {
-		log.Fatal().Msg("REDIS_URL/REDIS_PRIVATE_URL not set")
+		log.Fatal().Stack().Msg("REDIS_URL/REDIS_PRIVATE_URL not set")
 	}

 	// Parse URL and create client
 	options, err := redis.ParseURL(redisUrl)
 	if err != nil {
-		log.Fatal().Err(err).Msg("Cannot parse redis url")
+		log.Fatal().Stack().Err(err).Msg("Cannot parse redis url")
 	}
 	kv = redis.NewClient(options)

@@ -105,7 +108,7 @@ func initRedis() {
 	for {
 		pingCount++
 		if pingCount > totalPings {
-			log.Fatal().Err(lastPingErr).Msg("Reached ping limit while trying to connect")
+			log.Fatal().Stack().Err(lastPingErr).Msg("Reached ping limit while trying to connect")
 		}

 		// Ping redis
@@ -151,7 +154,7 @@ func main() {
 	})
 	err = session.Open()
 	if err != nil {
-		log.Fatal().Err(err).Msg("Cannot open the session")
+		log.Fatal().Stack().Err(err).Msg("Cannot open the session")
 	}

 	// Setup command handlers
@@ -208,12 +211,12 @@ func main() {
 				// Respond with error
 				err = RespondError(internalSession, interaction.Interaction, fmt.Sprintf("Unexpected Error: %s", err.Error()), nil)
 				if err != nil {
-					log.Error().Str("commandName", name).Err(err).Msg("Failed to respond with error feedback")
+					log.Error().Stack().Str("commandName", name).Err(err).Msg("Failed to respond with error feedback")
 				}
 			}

 		} else {
-			log.Error().Str("commandName", name).Msg("Command Interaction Has No Handler")
+			log.Error().Stack().Str("commandName", name).Msg("Command Interaction Has No Handler")

 			// Respond with error
 			RespondError(internalSession, interaction.Interaction, "Unexpected Error: interaction has no handler", nil)
@@ -236,11 +239,11 @@ func main() {
 	// Register commands
 	existingCommands, err := session.ApplicationCommands(session.State.User.ID, guildTarget)
 	if err != nil {
-		log.Fatal().Err(err).Msg("Cannot get existing commands")
+		log.Fatal().Stack().Err(err).Msg("Cannot get existing commands")
 	}
 	newCommands, err := session.ApplicationCommandBulkOverwrite(session.State.User.ID, guildTarget, commandDefinitions)
 	if err != nil {
-		log.Fatal().Err(err).Msg("Cannot register commands")
+		log.Fatal().Stack().Err(err).Msg("Cannot register commands")
 	}

 	// Compare existing commands with new commands
@@ -266,7 +269,7 @@ func main() {
 	// Fetch terms on startup
 	_, err = GetTerms("", 1, 10)
 	if err != nil {
-		log.Fatal().Err(err).Msg("Cannot get terms")
+		log.Fatal().Stack().Err(err).Msg("Cannot get terms")
 	}

 	// Term Select Pre-Search POST
@@ -279,7 +282,7 @@ func main() {
 		for {
 			err := Scrape()
 			if err != nil {
-				log.Err(err).Msg("Periodic Scrape Failed")
+				log.Err(err).Stack().Msg("Periodic Scrape Failed")
 			}

 			// Wait 5 minutes
--- a/meta.go
+++ b/meta.go
@@ -12,7 +12,7 @@ func GetGuildName(guildID string) string {
 	// Check Redis for the guild name
 	guildName, err := kv.Get(ctx, "guild:"+guildID+":name").Result()
 	if err != nil && err != redis.Nil {
-		log.Error().Err(err).Msg("Error getting guild name from Redis")
+		log.Error().Stack().Err(err).Msg("Error getting guild name from Redis")
 		return "err"
 	}

@@ -24,12 +24,12 @@ func GetGuildName(guildID string) string {
 	// If the guild name isn't in Redis, get it from Discord and cache it
 	guild, err := session.Guild(guildID)
 	if err != nil {
-		log.Error().Err(err).Msg("Error getting guild name")
+		log.Error().Stack().Err(err).Msg("Error getting guild name")

 		// Store an invalid value in Redis so we  don't keep trying to get the guild name
 		_, err := kv.Set(ctx, "guild:"+guildID+":name", "x", time.Minute*5).Result()
 		if err != nil {
-			log.Error().Err(err).Msg("Error setting false guild name in Redis")
+			log.Error().Stack().Err(err).Msg("Error setting false guild name in Redis")
 		}

 		return "unknown"
@@ -46,7 +46,7 @@ func GetChannelName(channelID string) string {
 	// Check Redis for the channel name
 	channelName, err := kv.Get(ctx, "channel:"+channelID+":name").Result()
 	if err != nil && err != redis.Nil {
-		log.Error().Err(err).Msg("Error getting channel name from Redis")
+		log.Error().Stack().Err(err).Msg("Error getting channel name from Redis")
 		return "err"
 	}

@@ -58,12 +58,12 @@ func GetChannelName(channelID string) string {
 	// If the channel name isn't in Redis, get it from Discord and cache it
 	channel, err := session.Channel(channelID)
 	if err != nil {
-		log.Error().Err(err).Msg("Error getting channel name")
+		log.Error().Stack().Err(err).Msg("Error getting channel name")

 		// Store an invalid value in Redis so we  don't keep trying to get the channel name
 		_, err := kv.Set(ctx, "channel:"+channelID+":name", "x", time.Minute*5).Result()
 		if err != nil {
-			log.Error().Err(err).Msg("Error setting false channel name in Redis")
+			log.Error().Stack().Err(err).Msg("Error setting false channel name in Redis")
 		}

 		return "unknown"
--- a/session.go
+++ b/session.go
@@ -23,7 +23,7 @@ func setup() {
 	// Validate that cookies were set
 	baseUrlParsed, err := url.Parse(baseURL)
 	if err != nil {
-		log.Fatal().Str("baseURL", baseURL).Err(err).Msg("Failed to parse baseURL")
+		log.Fatal().Stack().Str("baseURL", baseURL).Err(err).Msg("Failed to parse baseURL")
 	}

 	current_cookies := client.Jar.Cookies(baseUrlParsed)
--- a/types.go
+++ b/types.go
@@ -173,7 +173,7 @@ const layout = "01/02/2006"
 func (m *MeetingTimeResponse) StartDay() time.Time {
 	t, err := time.Parse(layout, m.MeetingTime.StartDate)
 	if err != nil {
-		log.Fatal().Err(err).Str("raw", m.MeetingTime.StartDate).Msg("Cannot parse start date")
+		log.Fatal().Stack().Err(err).Str("raw", m.MeetingTime.StartDate).Msg("Cannot parse start date")
 	}
 	return t
 }
@@ -183,7 +183,7 @@ func (m *MeetingTimeResponse) StartDay() time.Time {
 func (m *MeetingTimeResponse) EndDay() time.Time {
 	t, err := time.Parse(layout, m.MeetingTime.EndDate)
 	if err != nil {
-		log.Fatal().Err(err).Str("raw", m.MeetingTime.EndDate).Msg("Cannot parse end date")
+		log.Fatal().Stack().Err(err).Str("raw", m.MeetingTime.EndDate).Msg("Cannot parse end date")
 	}
 	return t
 }
@@ -198,7 +198,7 @@ func (m *MeetingTimeResponse) StartTime() *NaiveTime {

 	value, err := strconv.ParseUint(raw, 10, 32)
 	if err != nil {
-		log.Fatal().Err(err).Str("raw", raw).Msg("Cannot parse start time integer")
+		log.Fatal().Stack().Err(err).Str("raw", raw).Msg("Cannot parse start time integer")
 	}

 	return ParseNaiveTime(value)
@@ -214,7 +214,7 @@ func (m *MeetingTimeResponse) EndTime() *NaiveTime {

 	value, err := strconv.ParseUint(raw, 10, 32)
 	if err != nil {
-		log.Fatal().Err(err).Str("raw", raw).Msg("Cannot parse end time integer")
+		log.Fatal().Stack().Err(err).Str("raw", raw).Msg("Cannot parse end time integer")
 	}

 	return ParseNaiveTime(value)