diff --git a/client/localServer/localTestClient.go b/client/localServer/localTestClient.go index 191e9050..d6c2a2f4 100644 --- a/client/localServer/localTestClient.go +++ b/client/localServer/localTestClient.go @@ -30,7 +30,7 @@ func main() { conn, err := grpc.Dial(localAddress, grpc.WithTransportCredentials(insecure.NewCredentials())) if err != nil { - log.Info(err) + log.WithError(err).Error("could not dial localAddress") } c := pb.NewCampusClient(conn) ctx, cancel := context.WithTimeout(context.Background(), time.Second*5) @@ -50,8 +50,7 @@ func canteenHeadCount(c pb.CampusClient, ctx context.Context) { if err != nil { log.Error(err) } else { - log.Info("Canteen HeadCount data request successful.") - log.Info(res) + log.WithField("res", res).Info("Canteen HeadCount data request successful.") } } @@ -80,43 +79,52 @@ func queryDish(cafeteria string, dish string, c pb.CampusClient, ctx context.Con }) if err != nil { - log.Info(err) + log.WithError(err).Info("failed to query dish") } else { - log.Info("Result: ") - log.Info("\tavg : ", res.Avg) - log.Info("\tmin ", res.Min) - log.Info("\tmax ", res.Max) - log.Info("\tstd ", res.Std) - log.Info("Number of individual Ratings", len(res.Rating)) + fields := log.Fields{ + "avg": res.Avg, + "min": res.Min, + "max": res.Max, + "std": res.Std, + "individualRatings": len(res.Rating), + } + log.WithFields(fields).Info("succeeded to query dish") path := fmt.Sprintf("%s%d%s", "./testImages/dishes/", time.Now().Unix(), "/") for _, v := range res.Rating { - log.Info("\nRating: ", v.Points) - log.Info("Comment ", v.Comment) - log.Info("Number of Tag Ratings : ", len(v.RatingTags)) - log.Info("Timestamp: ", v.Visited) - log.Info("ImageLength:", len(v.Image)) + fields := log.Fields{ + "Rating": v.Points, + "Comment": v.Comment, + "Number of Tag Ratings": len(v.RatingTags), + "Timestamp": v.Visited, + "ImageLength": len(v.Image), + } + log.WithFields(fields).Info("storing image") if imageShouldBeStored { _, err := storeImage(path, v.Image) if err != nil { - log.Info("image was not saved successfully") + log.WithError(err).Error("image was not saved successfully") } } } log.Info("Rating Tags: ") for _, v := range res.RatingTags { - log.Info("TagId: ", v.TagId) - log.Info("\tavg: ", v.Avg) - log.Info("\tmin: ", v.Min) - log.Info("\tmax: ", v.Max) - log.Info("\tstd: ", v.Std) + fields := log.Fields{ + "avg": v.Avg, + "min": v.Min, + "max": v.Max, + "std": v.Std, + } + log.WithFields(fields).Info(v.TagId) } log.Info("nameTags: ") for _, v := range res.NameTags { - log.Info("TagId: ", v.TagId) - log.Info("\tavg: ", v.Avg) - log.Info("\tmin: ", v.Min) - log.Info("\tmax: ", v.Max) - log.Info("\tstd: ", v.Std) + fields := log.Fields{ + "avg": v.Avg, + "min": v.Min, + "max": v.Max, + "std": v.Std, + } + log.WithFields(fields).Info(v.TagId) } } } @@ -130,34 +138,42 @@ func queryCafeteria(s string, c pb.CampusClient, ctx context.Context, imageShoul }) if err != nil { - log.Info(err) + log.WithError(err).Error("failed to query cafeteria") } else { - log.Info("Result: ") - log.Info("avg: ", res.Avg) - log.Info("min", res.Min) - log.Info("max", res.Max) - log.Info("Number of individual Ratings", len(res.Rating)) + fields := log.Fields{ + "avg": res.Avg, + "min": res.Min, + "max": res.Max, + "std": res.Std, + "Number of individual Ratings": len(res.Rating), + } + log.WithFields(fields).Info("succeeded to query cafeteria") path := fmt.Sprintf("%s%d%s", "./testImages/cafeteria/", time.Now().Unix(), "/") - for _, v := range res.Rating { - log.Info("\nRating: ", v.Points) - log.Info("Comment ", v.Comment) - log.Info("Number of Tag Ratings: ", len(v.RatingTags)) - log.Info("Timestamp: ", v.Visited) - log.Info("ImageLength:", len(v.Image)) + for i, v := range res.Rating { + fields := log.Fields{ + "Rating": v.Points, + "Comment": v.Comment, + "Number of Tag Ratings": len(v.RatingTags), + "Timestamp": v.Visited, + "ImageLength": len(v.Image), + } + log.WithFields(fields).Infof("Rating %d", i) if imageShouldBeStored { _, err := storeImage(path, v.Image) if err != nil { - log.Info("image was not saved successfully") + log.WithError(err).Error("image was not saved successfully") } } } for _, v := range res.RatingTags { - log.Info("\nTagId: ", v.TagId) - log.Info("avg: ", v.Avg) - log.Info("min", v.Min) - log.Info("max", v.Max) - log.Info("std", v.Std) + fields := log.Fields{ + "avg": v.Avg, + "min": v.Min, + "max": v.Max, + "std": v.Std, + } + log.WithFields(fields).Info(v.TagId) } } } @@ -182,9 +198,9 @@ func generateCafeteriaRating(c pb.CampusClient, ctx context.Context, cafeteria s }) if err != nil { - log.Info(err) + log.WithError(err).Error("could not store new Cafeteria Rating") } else { - log.Info("Request successfully: Cafeteria Rating should be stored") + log.Info("Cafeteria Rating successfully be stored") } } @@ -213,9 +229,9 @@ func generateDishRating(c pb.CampusClient, ctx context.Context, cafeteria string }) if err != nil { - log.Info(err) + log.WithError(err).Error("failed to store dish rating") } else { - log.Info("Request successfully: Dish Rating should be stored") + log.Info("Dish Rating successfully stored") } } @@ -231,7 +247,7 @@ func getImageToBytes(path string) []byte { defer func(file *os.File) { err := file.Close() if err != nil { - log.Info("Request successfully: Dish Rating should be stored") + log.WithError(err).Error("could not close file") } }(file) @@ -239,12 +255,13 @@ func getImageToBytes(path string) []byte { var size = fileInfo.Size() byteArray := make([]byte, size) - buffer := bufio.NewReader(file) - _, err = buffer.Read(byteArray) + n, err := bufio.NewReader(file).Read(byteArray) + fields := log.Fields{"readBytes": n, "len(byteArray)": len(byteArray)} if err != nil { - log.Info("Unable to read the byteArray") + log.WithError(err).Error("Unable to read the byteArray") + } else { + log.WithFields(fields).Info("read image to byteArray") } - log.Info("Length of the image as bytes: ", len(byteArray)) return byteArray } @@ -252,7 +269,7 @@ func storeImage(path string, i []byte) (string, error) { if _, err := os.Stat(path); errors.Is(err, os.ErrNotExist) { err := os.MkdirAll(path, os.ModePerm) if err != nil { - log.Info(err) + log.WithError(err).Error("could not make dir") } } img, _, _ := image.Decode(bytes.NewReader(i)) @@ -271,12 +288,12 @@ func storeImage(path string, i []byte) (string, error) { out, errFile := os.Create(imgPath) if errFile != nil { - log.Info("Unable to create the new testfile") + log.WithError(errFile).Error("Unable to create the new testfile") } defer func(out *os.File) { err := out.Close() if err != nil { - log.Info("File was not closed successfully") + log.WithError(err).Error("File was not closed successfully") } }(out) var opts jpeg.Options diff --git a/client/publicServer/client.go b/client/publicServer/client.go index 8e53ed1f..7db84b6a 100644 --- a/client/publicServer/client.go +++ b/client/publicServer/client.go @@ -4,11 +4,11 @@ import ( "context" "crypto/x509" pb "github.com/TUM-Dev/Campus-Backend/api" + log "github.com/sirupsen/logrus" "google.golang.org/grpc" "google.golang.org/grpc/credentials" "google.golang.org/grpc/metadata" "google.golang.org/protobuf/types/known/emptypb" - "log" "time" ) @@ -18,16 +18,21 @@ const ( func main() { // Set up a connection to the server. - log.Println("Connecting...") + log.Info("Connecting...") pool, _ := x509.SystemCertPool() // error handling omitted creds := credentials.NewClientTLSFromCert(pool, "") conn, err := grpc.Dial(address, grpc.WithTransportCredentials(creds)) if err != nil { - log.Fatalf("did not connect: %v", err) + log.WithError(err).Fatalf("did not connect") } - defer conn.Close() + defer func(conn *grpc.ClientConn) { + err := conn.Close() + if err != nil { + log.WithError(err).Error("did not close connection") + } + }(conn) c := pb.NewCampusClient(conn) ctx, cancel := context.WithTimeout(context.Background(), time.Second*5) @@ -37,10 +42,10 @@ func main() { md := metadata.New(map[string]string{"x-device-id": "grpc-tests"}) ctx = metadata.NewOutgoingContext(ctx, md) - log.Println("Trying to fetch top news") - r, err := c.GetTopNews(ctx, &emptypb.Empty{}) - if err != nil { - log.Fatalf("could not greet: %v", err) + log.Info("Trying to fetch top news") + if r, err := c.GetTopNews(ctx, &emptypb.Empty{}); err != nil { + log.WithError(err).Fatal("could not greet") + } else { + log.WithField("topNewsResponse", r.String()).Info("fetched top news successfully") } - log.Printf("Greeting: %s", r.String()) } diff --git a/server/backend/cafeteriaRatingDBInitializer.go b/server/backend/cafeteriaRatingDBInitializer.go index b8fd3056..1f80d270 100644 --- a/server/backend/cafeteriaRatingDBInitializer.go +++ b/server/backend/cafeteriaRatingDBInitializer.go @@ -50,7 +50,7 @@ func addEntriesForCronJob(db *gorm.DB, cronName string, interval int32) { Error if err != nil { - log.WithError(err).Errorf("Error while checking if cronjob with name %s already exists in database", cronName) + log.WithError(err).WithField("cronName", cronName).Error("Error while checking if cronjob already exists in database") } else if count == 0 { errCreate := db.Model(&model.Crontab{}). Create(&model.Crontab{ @@ -78,8 +78,9 @@ func updateNameTagOptions(db *gorm.DB) { Where("EN LIKE ? AND DE LIKE ?", v.TagNameEnglish, v.TagNameGerman). Select("DishNameTagOption"). Scan(&parentId) + fields := log.Fields{"en": v.TagNameEnglish, "de": v.TagNameGerman} if res.Error != nil { - log.WithError(res.Error).Errorf("Unable to load tag with En %s and De %s", v.TagNameEnglish, v.TagNameGerman) + log.WithError(res.Error).WithFields(fields).Error("Unable to load tag") } if res.RowsAffected == 0 || res.Error != nil { parent := model.DishRatingTagOption{ @@ -87,17 +88,14 @@ func updateNameTagOptions(db *gorm.DB) { EN: v.TagNameEnglish, } - errCreate := db.Model(&model.DishNameTagOption{}). - Create(&parent).Error - if errCreate != nil { - log.WithError(errCreate).Error("Error while creating tag {}, {}.", v.TagNameGerman, v.TagNameEnglish) + if err := db.Model(&model.DishNameTagOption{}).Create(&parent).Error; err != nil { + log.WithError(err).WithFields(fields).Error("Error while creating tag") } parentId = parent.DishRatingTagOption } addCanBeIncluded(parentId, db, v) addNotIncluded(parentId, db, v) - } } @@ -161,20 +159,20 @@ func updateTagTable(path string, db *gorm.DB, tagType modelType) { insertModel := getTagModel(tagType, db) for _, v := range tagsDish.MultiLanguageTags { var count int64 - + fields := log.Fields{"de": v.TagNameGerman, "en": v.TagNameEnglish} if tagType == CAFETERIA { countError := db.Model(&model.CafeteriaRatingTagOption{}). Where("EN LIKE ? AND DE LIKE ?", v.TagNameEnglish, v.TagNameGerman). Select("cafeteriaRatingTagOption").Count(&count).Error if countError != nil { - log.WithError(countError).Errorf("Unable to find cafeteria rating tag with En %s and De %s", v.TagNameGerman, v.TagNameEnglish) + log.WithError(countError).WithFields(fields).Error("Unable to find cafeteria rating tag") } } else { countError := db.Model(&model.DishRatingTagOption{}). Where("EN LIKE ? AND DE LIKE ?", v.TagNameEnglish, v.TagNameGerman). Select("dishRatingTagOption").Count(&count).Error if countError != nil { - log.WithError(countError).Errorf("Unable to find dish rating tag with En %s and De %s", v.TagNameGerman, v.TagNameEnglish) + log.WithError(countError).WithFields(fields).Error("Unable to find dish rating tag") } } @@ -185,9 +183,9 @@ func updateTagTable(path string, db *gorm.DB, tagType modelType) { } createError := insertModel.Create(&element).Error if createError != nil { - log.WithError(createError).Errorf("Unable to create new can be excluded tag with En %s and De %s", v.TagNameGerman, v.TagNameEnglish) + log.WithError(createError).WithFields(fields).Error("Unable to create new can be excluded tag") } else { - log.Infof("New Entry with En %s and De %s successfully created.", v.TagNameGerman, v.TagNameEnglish) + log.WithFields(fields).Info("New Entry successfully created") } } } diff --git a/server/backend/cafeteriaService.go b/server/backend/cafeteriaService.go index 55acd47a..c0573a27 100644 --- a/server/backend/cafeteriaService.go +++ b/server/backend/cafeteriaService.go @@ -115,7 +115,7 @@ func queryLastCafeteriaRatingsWithLimit(input *pb.CafeteriaRatingRequest, cafete } if err != nil { - log.WithError(err).Error("Error while querying last cafeteria ratings.") + log.WithError(err).Error("while querying last cafeteria ratings.") return make([]*pb.SingleRatingReply, 0) } ratingResults := make([]*pb.SingleRatingReply, len(ratings)) @@ -224,7 +224,7 @@ func queryLastDishRatingsWithLimit(input *pb.DishRatingRequest, cafeteriaID int3 } if err != nil { - log.WithError(err).Error("Error while querying last dish ratings from Database.") + log.WithError(err).Error("while querying last dish ratings from Database.") return make([]*pb.SingleRatingReply, 0) } ratingResults := make([]*pb.SingleRatingReply, len(ratings)) @@ -251,7 +251,7 @@ func getImageToBytes(path string) []byte { file, err := os.Open(path) if err != nil { - log.WithError(err).Error("Error while opening image file with path: ", path) + log.WithError(err).Error("while opening image file with path: ", path) return nil } @@ -269,7 +269,7 @@ func getImageToBytes(path string) []byte { buffer := bufio.NewReader(file) _, err = buffer.Read(imageAsBytes) if err != nil { - log.WithError(err).Error("Error while trying to read image as bytes") + log.WithError(err).Error("while trying to read image as bytes") return nil } return imageAsBytes @@ -315,7 +315,7 @@ func queryTags(db *gorm.DB, cafeteriaID int32, dishID int32, ratingType modelTyp } if err != nil { - log.WithError(err).Error("Error while querying the tags for the request.") + log.WithError(err).Error("while querying the tags for the request.") } //needed since the gRPC element does not specify column names - cannot be directly queried into the grpc message object. @@ -351,7 +351,7 @@ func queryTagRatingsOverviewForRating(s *CampusServer, dishID int32, ratingType } if err != nil { - log.WithError(err).Error("Error while querying the tag rating overview.") + log.WithError(err).Error("while querying the tag rating overview.") } return results } @@ -406,7 +406,7 @@ func storeImage(path string, i []byte) (string, error) { if _, err := os.Stat(path); errors.Is(err, os.ErrNotExist) { err := os.MkdirAll(path, os.ModePerm) if err != nil { - log.WithError(err).Errorf("Directory with path %s could not be created successfully", path) + log.WithError(err).WithField("path", path).Error("Directory could not be created successfully") return "", nil } } @@ -432,7 +432,7 @@ func storeImage(path string, i []byte) (string, error) { defer func(out *os.File) { err := out.Close() if err != nil { - log.WithError(err).Error("Error while closing the file.") + log.WithError(err).Error("while closing the file.") } }(out) @@ -475,7 +475,7 @@ func (s *CampusServer) NewDishRating(_ context.Context, input *pb.NewDishRatingR err := s.db.Model(&model.DishRating{}).Create(&rating).Error if err != nil { - log.WithError(err).Error("Error while creating a new dish rating.") + log.WithError(err).Error("while creating a new dish rating.") return nil, status.Errorf(codes.Internal, "Error while creating the new rating in the database. Rating has not been saved.") } @@ -492,7 +492,7 @@ func assignDishNameTag(s *CampusServer, rating model.DishRating, dishID int32) { Select("nameTagID"). Scan(&result).Error if err != nil { - log.WithError(err).Error("Error while loading the dishID for the given name.") + log.WithError(err).Error("while loading the dishID for the given name.") } else { for _, tagID := range result { err := s.db.Model(&model.DishNameTag{}).Create(&model.DishNameTag{ @@ -501,7 +501,7 @@ func assignDishNameTag(s *CampusServer, rating model.DishRating, dishID int32) { TagNameID: tagID, }).Error if err != nil { - log.WithError(err).Error("Error while creating a new dish name rating.") + log.WithError(err).Error("while creating a new dish name rating.") } } } @@ -558,7 +558,11 @@ func storeRatingTags(s *CampusServer, parentRatingID int32, tags []*pb.RatingTag } if err == gorm.ErrRecordNotFound || count == 0 { - log.Info("tag with tagid ", currentTag.TagId, "does not exist") + fields := log.Fields{ + "tagid": currentTag.TagId, + "count": count, + } + log.WithFields(fields).Info("tag does not exist") errorOccurred = fmt.Sprintf("%s, %d", errorOccurred, currentTag.TagId) } else { if usedTagIds[int(currentTag.TagId)] == 0 { @@ -569,7 +573,7 @@ func storeRatingTags(s *CampusServer, parentRatingID int32, tags []*pb.RatingTag TagID: int(currentTag.TagId), }).Error if err != nil { - log.WithError(err).Error("Error while Creating a currentTag rating for a new rating.") + log.WithError(err).Error("while Creating a currentTag rating for a new rating.") } usedTagIds[int(currentTag.TagId)] = 1 @@ -609,7 +613,7 @@ func getIDForCafeteriaName(name string, db *gorm.DB) int32 { Select("cafeteria"). Scan(&result).Error if err != nil { - log.WithError(err).Error("Error while querying the cafeteria name.") + log.WithError(err).Error("while querying the cafeteria name.") result = -1 } return result @@ -622,7 +626,7 @@ func getIDForDishName(name string, cafeteriaID int32, db *gorm.DB) int32 { Select("dish"). Scan(&result).Error if err != nil { - log.WithError(err).Error("Error while querying the dish name.") + log.WithError(err).Error("while querying the dish name.") result = -1 } @@ -636,7 +640,7 @@ func (s *CampusServer) GetAvailableDishTags(_ context.Context, _ *emptypb.Empty) var requestStatus error = nil err := s.db.Model(&model.DishRatingTagOption{}).Select("DE as de, EN as en, dishRatingTagOption as TagId").Find(&result).Error if err != nil { - log.WithError(err).Error("Error while loading Cafeterias from database.") + log.WithError(err).Error("while loading Cafeterias from database.") requestStatus = status.Errorf(codes.Internal, "Available dish tags could not be loaded from the database.") } @@ -652,7 +656,7 @@ func (s *CampusServer) GetNameTags(_ context.Context, _ *emptypb.Empty) (*pb.Get var requestStatus error = nil err := s.db.Model(&model.DishNameTagOption{}).Select("DE as de, EN as en, dishNameTagOption as TagId").Find(&result).Error if err != nil { - log.WithError(err).Error("Error while loading available Name Tags from database.") + log.WithError(err).Error("while loading available Name Tags from database.") requestStatus = status.Errorf(codes.Internal, "Available dish tags could not be loaded from the database.") } @@ -668,7 +672,7 @@ func (s *CampusServer) GetAvailableCafeteriaTags(_ context.Context, _ *emptypb.E var requestStatus error = nil err := s.db.Model(&model.CafeteriaRatingTagOption{}).Select("DE as de, EN as en, cafeteriaRatingsTagOption as TagId").Find(&result).Error if err != nil { - log.WithError(err).Error("Error while loading Cafeterias from database.") + log.WithError(err).Error("while loading Cafeterias from database.") requestStatus = status.Errorf(codes.Internal, "Available cafeteria tags could not be loaded from the database.") } @@ -684,7 +688,7 @@ func (s *CampusServer) GetCafeterias(_ context.Context, _ *emptypb.Empty) (*pb.G var requestStatus error = nil err := s.db.Model(&model.Cafeteria{}).Select("cafeteria as id,address,latitude,longitude").Scan(&result).Error if err != nil { - log.WithError(err).Error("Error while loading Cafeterias from database.") + log.WithError(err).Error("while loading Cafeterias from database.") requestStatus = status.Errorf(codes.Internal, "Cafeterias could not be loaded from the database.") } @@ -716,7 +720,7 @@ func (s *CampusServer) GetDishes(_ context.Context, request *pb.GetDishesRequest Find(&results).Error if err != nil { - log.WithError(err).Error("Error while loading Cafeterias from database.") + log.WithError(err).Error("while loading Cafeterias from database.") requestStatus = status.Errorf(codes.Internal, "Cafeterias could not be loaded from the database.") } diff --git a/server/backend/campus_api/campusApi.go b/server/backend/campus_api/campusApi.go index fc59c0da..1a3d192d 100644 --- a/server/backend/campus_api/campusApi.go +++ b/server/backend/campus_api/campusApi.go @@ -28,7 +28,7 @@ func FetchGrades(token string) (*model.IOSGrades, error) { req, err := http.NewRequest(http.MethodGet, requestUrl, nil) if err != nil { - log.Errorf("Error while creating request: %s", err) + log.WithError(err).Error("Failed to create api-request") return nil, ErrCannotCreateRequest } @@ -40,14 +40,14 @@ func FetchGrades(token string) (*model.IOSGrades, error) { resp, err := http.DefaultClient.Do(req) if err != nil { - log.Errorf("Error while fetching grades: %s", err) + log.WithError(err).Error("failed to fetch grades") return nil, ErrWhileFetchingGrades } defer func(Body io.ReadCloser) { err := Body.Close() if err != nil { - log.Errorf("Error while closing body: %s", err) + log.WithError(err).Error("Could not close body") } }(resp.Body) @@ -55,7 +55,7 @@ func FetchGrades(token string) (*model.IOSGrades, error) { err = xml.NewDecoder(resp.Body).Decode(&grades) if err != nil { - log.Errorf("Error while unmarshalling grades: %s", err) + log.WithError(err).Error("could not unmarshall grades") return nil, ErrorWhileUnmarshalling } diff --git a/server/backend/canteenHeadCount.go b/server/backend/canteenHeadCount.go index d3c0293f..58af641f 100644 --- a/server/backend/canteenHeadCount.go +++ b/server/backend/canteenHeadCount.go @@ -16,7 +16,7 @@ func (s *CampusServer) GetCanteenHeadCount(_ context.Context, input *pb.GetCante data := model.CanteenHeadCount{Count: 0, MaxCount: 0, Percent: -1} // Initialize with an empty (not found) value err := s.db.Model(&model.CanteenHeadCount{}).Where(model.CanteenHeadCount{CanteenId: input.CanteenId}).FirstOrInit(&data).Error if err != nil && !errors.Is(err, gorm.ErrRecordNotFound) { - log.WithError(err).Error("Error while querying the canteen head count for: ", input.CanteenId) + log.WithError(err).Error("while querying the canteen head count for: ", input.CanteenId) return nil, errors.New("failed to query head count") } diff --git a/server/backend/cron/averageRatingComputation.go b/server/backend/cron/averageRatingComputation.go index b80cff0c..24bd0a6c 100644 --- a/server/backend/cron/averageRatingComputation.go +++ b/server/backend/cron/averageRatingComputation.go @@ -26,7 +26,7 @@ func computeAverageNameTags(c *CronService) { " GROUP BY mr.cafeteriaID, mnt.tagnameID").Scan(&results).Error if err != nil { - log.WithError(err).Error("Error while precomputing average name tags.") + log.WithError(err).Error("while precomputing average name tags.") } else if len(results) > 0 { errDelete := c.db.Where("1=1").Delete(&model.DishNameTagAverage{}).Error // Does not work with "true" if errDelete != nil { @@ -34,7 +34,7 @@ func computeAverageNameTags(c *CronService) { } err := c.db.Model(&model.DishNameTagAverage{}).Create(&results).Error if err != nil { - log.WithError(err).Error("Error while creating a new average name tag rating in the database.") + log.WithError(err).Error("while creating a new average name tag rating in the database.") } } } @@ -47,7 +47,7 @@ func computeAverageForDishesInCafeteriasTags(c *CronService) { " GROUP BY mr.cafeteriaID, mrt.tagID, mr.dishID").Scan(&results).Error if err != nil { - log.WithError(err).Error("Error while precomputing average dish tags.") + log.WithError(err).Error("while precomputing average dish tags.") } else if len(results) > 0 { errDelete := c.db.Where("1=1").Delete(&model.DishRatingTagAverage{}).Error if errDelete != nil { @@ -56,7 +56,7 @@ func computeAverageForDishesInCafeteriasTags(c *CronService) { err := c.db.Model(&model.DishRatingTagAverage{}).Create(&results).Error if err != nil { - log.WithError(err).Error("Error while creating a new average dish tag rating in the database.") + log.WithError(err).Error("while creating a new average dish tag rating in the database.") } } @@ -70,7 +70,7 @@ func computeAverageCafeteriaTags(c *CronService) { " GROUP BY cr.cafeteriaID, crt.tagID").Scan(&results).Error if err != nil { - log.WithError(err).Error("Error while precomputing average cafeteria tags.") + log.WithError(err).Error("while precomputing average cafeteria tags.") } else if len(results) > 0 { errDelete := c.db.Where("1=1").Delete(&model.CafeteriaRatingTagsAverage{}).Error if errDelete != nil { @@ -79,7 +79,7 @@ func computeAverageCafeteriaTags(c *CronService) { err := c.db.Model(&model.CafeteriaRatingTagsAverage{}).Create(&results).Error if err != nil { - log.WithError(err).Error("Error while creating a new average cafeteria tag rating in the database.") + log.WithError(err).Error("while creating a new average cafeteria tag rating in the database.") } } } @@ -91,7 +91,7 @@ func computeAverageForDishesInCafeterias(c *CronService) { Group("cafeteriaID,dishID").Scan(&results).Error if err != nil { - log.WithError(err).Error("Error while precomputing average dish ratings.") + log.WithError(err).Error("while precomputing average dish ratings.") } else if len(results) > 0 { errDelete := c.db.Where("1=1").Delete(&model.DishRatingAverage{}).Error if errDelete != nil { @@ -99,7 +99,7 @@ func computeAverageForDishesInCafeterias(c *CronService) { } err := c.db.Model(&model.DishRatingAverage{}).Create(&results).Error if err != nil { - log.WithError(err).Error("Error while creating a new average dish rating in the database.") + log.WithError(err).Error("while creating a new average dish rating in the database.") } } } @@ -111,7 +111,7 @@ func computeAverageForCafeteria(c *CronService) { Group("cafeteriaID").Find(&results).Error if err != nil { - log.WithError(err).Error("Error while precomputing average cafeteria ratings.") + log.WithError(err).Error("while precomputing average cafeteria ratings.") } else if len(results) > 0 { errDelete := c.db.Where("1=1").Delete(&model.CafeteriaRatingAverage{}).Error if errDelete != nil { @@ -120,7 +120,7 @@ func computeAverageForCafeteria(c *CronService) { err := c.db.Model(&model.CafeteriaRatingAverage{}).Create(&results).Error if err != nil { - log.WithError(err).Error("Error while creating a new average cafeteria rating in the database.") + log.WithError(err).Error("while creating a new average cafeteria rating in the database.") } } } diff --git a/server/backend/cron/canteenHeadCount.go b/server/backend/cron/canteenHeadCount.go index 168af083..5f42ddfe 100644 --- a/server/backend/cron/canteenHeadCount.go +++ b/server/backend/cron/canteenHeadCount.go @@ -4,6 +4,7 @@ import ( "encoding/json" "errors" "fmt" + "io" "net/http" "strings" "time" @@ -128,17 +129,17 @@ CanteenApInformation when performing a request. const BaseUrl = "http://graphite-kom.srv.lrz.de/render/?from=-10min&target=%s&format=json" func (c *CronService) canteenHeadCountCron() error { - log.Info("Updating canteen head count stats...") + log.Debug("Updating canteen head count stats...") for _, canteen := range Canteens { if len(canteen.Target) <= 0 { - log.Debug("Skipping canteen head count stats for '", canteen.CanteenId, "', since there is no target.") + log.WithField("CanteenId", canteen.CanteenId).Debug("Skipping canteen head count stats, since there is no target.") continue } - log.Debug("Updating canteen head count stats for: ", canteen.CanteenId) + log.WithField("CanteenId", canteen.CanteenId).Debug("Updating canteen head count stats") aps := canteen.requestApData() if len(aps) <= 0 { - log.Debug("No canteen head count data points found for: ", canteen.CanteenId) + log.WithField("CanteenId", canteen.CanteenId).Debug("No canteen head count data points found") continue } @@ -150,7 +151,7 @@ func (c *CronService) canteenHeadCountCron() error { log.WithFields(fields).Debug("Canteen head count stats updated") } } - log.Info("Canteen head count stats updated.") + log.Debug("Canteen head count stats updated.") return nil } @@ -183,11 +184,22 @@ func updateDb(canteen *CanteenApInformation, count uint32, db *gorm.DB) error { res := db.Model(&model.CanteenHeadCount{}).Where(model.CanteenHeadCount{CanteenId: canteen.CanteenId}).Updates(&entry) if res.Error != nil { + log.WithError(res.Error).WithField("CanteenId", canteen.CanteenId).Error("could not update all instances of headcount") return res.Error } if res.RowsAffected == 0 { - return db.Create(&entry).Error + err := db.Create(&entry).Error + if err != nil { + fields := log.Fields{ + "CanteenId": entry.CanteenId, + "Count": entry.Count, + "MaxCount": entry.MaxCount, + "Percent": entry.Percent, + "Timestamp": entry.Timestamp} + log.WithError(res.Error).WithFields(fields).Error("could not create headcount entry") + } + return err } return nil } @@ -197,13 +209,18 @@ func (canteen CanteenApInformation) requestApData() []AccessPoint { url := fmt.Sprintf(BaseUrl, canteen.Target) resp, err := http.Get(url) if err != nil { - log.WithError(err).Error("Canteen HeadCount web request failed for: ", canteen.CanteenId) + log.WithError(err).WithField("CanteenId", canteen.CanteenId).Error("Canteen HeadCount web request failed") return []AccessPoint{} } // Ensure we close the body once we leave this function if resp.Body != nil { - defer resp.Body.Close() + defer func(Body io.ReadCloser) { + err := Body.Close() + if err != nil { + log.WithError(err).Error("Could not close body") + } + }(resp.Body) } // Parse as JSON diff --git a/server/backend/cron/cronjobs.go b/server/backend/cron/cronjobs.go index 508a4a08..ae5348f1 100644 --- a/server/backend/cron/cronjobs.go +++ b/server/backend/cron/cronjobs.go @@ -48,7 +48,7 @@ func New(db *gorm.DB, mensaCronActivated bool) *CronService { } func (c *CronService) Run() error { - log.WithField("useMensa", c.useMensa).Trace("running cron service") + log.WithField("MensaCronsRunning", c.useMensa).Trace("running cron service") g := new(errgroup.Group) g.Go(func() error { return c.dishNameDownloadCron() }) diff --git a/server/backend/cron/dishNameDownload.go b/server/backend/cron/dishNameDownload.go index 1dab432e..5db223e7 100644 --- a/server/backend/cron/dishNameDownload.go +++ b/server/backend/cron/dishNameDownload.go @@ -71,13 +71,17 @@ func downloadDailyDishes(c *CronService) { cafeteriaName := strings.Replace(strings.ToLower(v.Name), "_", "-", 10) req := fmt.Sprintf("https://tum-dev.github.io/eat-api/%s/%d/%d.json", cafeteriaName, year, week) - log.Info("Fetching menu from: ", req) + log.WithField("req", req).Debug("Fetching menu") var resp, err = http.Get(req) if err != nil { log.WithError(err).Error("Error fetching menu.") } if resp.StatusCode != 200 { - log.WithError(err).Errorf("Menu for %s does not exist error 404 returned.", v.Name) + fields := log.Fields{ + "Name": v.Name, + "StatusCode": resp.StatusCode, + } + log.WithError(err).WithFields(fields).Error("Menu does not exist") } else { var dishes days errJson := json.NewDecoder(resp.Body).Decode(&dishes) diff --git a/server/backend/cron/news.go b/server/backend/cron/news.go index 4a7f4723..2485993d 100644 --- a/server/backend/cron/news.go +++ b/server/backend/cron/news.go @@ -65,7 +65,7 @@ func (c *CronService) newsCron(cronjob *model.Crontab) error { // parseNewsFeed processes a single news feed, extracts titles, content etc and saves it to the database func (c *CronService) parseNewsFeed(source model.NewsSource) error { - log.Printf("processing source %s", source.URL.String) + log.WithField("url", source.URL.String).Trace("processing newsfeed") feed, err := c.gf.ParseURL(source.URL.String) if err != nil { log.Printf("error parsing rss: %v", err) @@ -129,22 +129,26 @@ func (c *CronService) parseNewsFeed(source model.NewsSource) error { newNews = append(newNews, newsItem) } } - if len(newNews) != 0 { - log.Printf("Inserting %v new news", len(newNews)) + if ammountOfNewNews := len(newNews); ammountOfNewNews != 0 { err = c.db.Save(&newNews).Error + if err != nil { + log.WithField("ammountOfNewNews", ammountOfNewNews).Error("Inserting new news failed") + } else { + log.WithField("ammountOfNewNews", ammountOfNewNews).Trace("Inserting new news") + } return err } return nil } -// saveImage Saves an image to the database so it can be downloaded by another cronjob and returns it's id +// saveImage Saves an image to the database so it can be downloaded by another cronjob and returns its id func (c *CronService) saveImage(url string) (null.Int, error) { targetFileName := fmt.Sprintf("%x.jpg", md5.Sum([]byte(url))) var fileId null.Int if err := c.db.Model(model.Files{}). Where("name = ?", targetFileName). - Select("file").Scan(&fileId).Error; err != nil && err != gorm.ErrRecordNotFound { - log.Printf("Couldn't query database for file: %v", err) + Select("file").Scan(&fileId).Error; err != nil && !errors.Is(err, gorm.ErrRecordNotFound) { + log.WithError(err).WithField("targetFileName", targetFileName).Error("Couldn't query database for file") return null.Int{}, err } if fileId.Valid { // file already in database -> return for current news. @@ -186,9 +190,9 @@ func skipNews(existingLinks []string, link string) bool { } func (c *CronService) cleanOldNewsForSource(source int32) error { - log.Printf("Truncating old entries for source %d\n", source) + log.WithField("source", source).Trace("Truncating old entries") if res := c.db.Delete(&model.News{}, "`src` = ? AND `created` < ?", source, time.Now().Add(time.Hour*24*365*-1)); res.Error == nil { - log.Infof("cleaned up %v old news", res.RowsAffected) + log.WithField("RowsAffected", res.RowsAffected).Info("cleaned up old news") } else { log.WithError(res.Error).Error("failed to clean up old news") sentry.CaptureException(res.Error) diff --git a/server/backend/ios_notifications/ios_apns/iosAPNsRepository.go b/server/backend/ios_notifications/ios_apns/iosAPNsRepository.go index b184a4bb..1091b8f7 100644 --- a/server/backend/ios_notifications/ios_apns/iosAPNsRepository.go +++ b/server/backend/ios_notifications/ios_apns/iosAPNsRepository.go @@ -107,7 +107,7 @@ func (r *Repository) SendNotification(notification *model.IOSNotificationPayload defer func(Body io.ReadCloser) { err := Body.Close() if err != nil { - log.Errorf("Error while closing body: %s", err) + log.WithError(err).Error("Could not close body") } }(resp.Body) diff --git a/server/backend/ios_notifications/ios_apns/iosAPNsService.go b/server/backend/ios_notifications/ios_apns/iosAPNsService.go index d81fdff9..37427fca 100644 --- a/server/backend/ios_notifications/ios_apns/iosAPNsService.go +++ b/server/backend/ios_notifications/ios_apns/iosAPNsService.go @@ -28,7 +28,7 @@ func (s *Service) RequestGradeUpdateForDevice(deviceID string) error { campusRequestToken, err := s.Repository.CreateCampusTokenRequest(deviceID) if err != nil { - log.Errorf("Could not create campus token request: %s", err) + log.WithError(err).Error("Could not create campus token request") return ErrCouldNotCreateTokenRequest } @@ -37,7 +37,7 @@ func (s *Service) RequestGradeUpdateForDevice(deviceID string) error { res, err := s.Repository.SendBackgroundNotification(notification) if err != nil { - log.Errorf("Could not send background notification: %s", err) + log.WithError(err).Error("Could not send background notification") return ErrCouldNotSendNotification } diff --git a/server/backend/ios_notifications/ios_devices_activity_reset/iosDevicesActivityResetRepository.go b/server/backend/ios_notifications/ios_devices_activity_reset/iosDevicesActivityResetRepository.go index e827c93e..12f7207c 100644 --- a/server/backend/ios_notifications/ios_devices_activity_reset/iosDevicesActivityResetRepository.go +++ b/server/backend/ios_notifications/ios_devices_activity_reset/iosDevicesActivityResetRepository.go @@ -104,8 +104,8 @@ func (repo *Repository) CreateInitialRecords() { LastReset: now, } - if err := repo.DB.Create(&reset); err != nil { - log.Errorf("Failed to create initial %s type: %v", resetType, err) + if err := repo.DB.Create(&reset).Error; err != nil { + log.WithError(err).WithField("resetType", resetType).Error("Failed to create IOSDevicesActivityReset") continue } } diff --git a/server/backend/ios_notifications/ios_devices_activity_reset/iosDevicesActivityResetService.go b/server/backend/ios_notifications/ios_devices_activity_reset/iosDevicesActivityResetService.go index c3d29060..ddea9248 100644 --- a/server/backend/ios_notifications/ios_devices_activity_reset/iosDevicesActivityResetService.go +++ b/server/backend/ios_notifications/ios_devices_activity_reset/iosDevicesActivityResetService.go @@ -44,41 +44,41 @@ func (service *Service) HandleScheduledActivityReset() error { if now.Sub(daily.LastReset).Hours() > 24 { if err := service.Repository.ResettedDevicesDaily(); err != nil { - log.Errorf("Error while resetting devices daily: %s", err) + log.WithError(err).Error("while resetting devices daily") } if err := devicesRepo.ResetDevicesDailyActivity(); err != nil { - log.Errorf("Error while resetting devices daily activity: %s", err) + log.WithError(err).Error("while resetting devices daily activity") } } if now.Sub(weekly.LastReset).Hours() > 168 { if err := service.Repository.ResettedDevicesWeekly(); err != nil { - log.Errorf("Error while resetting devices weekly: %s", err) + log.WithError(err).Error("while resetting devices weekly") } if err := devicesRepo.ResetDevicesWeeklyActivity(); err != nil { - log.Errorf("Error while resetting devices weekly activity: %s", err) + log.WithError(err).Error("while resetting devices weekly activity") } } if now.Sub(monthly.LastReset).Hours() > 730 { if err := service.Repository.ResettedDevicesMonthly(); err != nil { - log.Errorf("Error while resetting devices monthly: %s", err) + log.WithError(err).Error("while resetting devices monthly") } if err := devicesRepo.ResetDevicesMonthlyActivity(); err != nil { - log.Errorf("Error while resetting devices monthly activity: %s", err) + log.WithError(err).Error("while resetting devices monthly activity") } } if now.Sub(yearly.LastReset).Hours() > 8760 { if err := service.Repository.ResettedDevicesYearly(); err != nil { - log.Errorf("Error while resetting devices yearly: %s", err) + log.WithError(err).Error("while resetting devices yearly") } if err := devicesRepo.ResetDevicesYearlyActivity(); err != nil { - log.Errorf("Error while resetting devices yearly activity: %s", err) + log.WithError(err).Error("while resetting devices yearly activity") } } diff --git a/server/backend/ios_notifications/ios_request_response/iosRequestResponseService.go b/server/backend/ios_notifications/ios_request_response/iosRequestResponseService.go index aab49934..32a3faa9 100644 --- a/server/backend/ios_notifications/ios_request_response/iosRequestResponseService.go +++ b/server/backend/ios_notifications/ios_request_response/iosRequestResponseService.go @@ -33,7 +33,7 @@ func (service *Service) HandleDeviceRequestResponse(request *pb.IOSDeviceRequest // requestId refers to the request id that was sent to the device and stored in the Database requestId := request.GetRequestId() - log.Infof("Handling request with id %s", requestId) + log.WithField("requestId", requestId).Info("Handling request") requestLog, err := service.Repository.GetIOSDeviceRequest(requestId) @@ -63,7 +63,7 @@ func (service *Service) HandleDeviceRequestResponse(request *pb.IOSDeviceRequest } func (service *Service) handleDeviceCampusTokenRequest(requestLog *model.IOSDeviceRequestLog, campusToken string) (*pb.IOSDeviceRequestResponseReply, error) { - log.Infof("Handling campus token request for device %s", requestLog.DeviceID) + log.WithField("DeviceID", requestLog.DeviceID).Info("Handling campus token request") userRepo := ios_device.NewRepository(service.Repository.DB) @@ -110,7 +110,7 @@ func (service *Service) handleDeviceCampusTokenRequest(requestLog *model.IOSDevi service.encryptGradesAndStoreInDatabase(apiGrades.Grades, requestLog.DeviceID, campusToken) - log.Infof("Found %d old grades and %d new grades", len(oldGrades), len(newGrades)) + log.WithFields(log.Fields{"old": len(oldGrades), "new": len(newGrades)}).Info("Found grades") if len(newGrades) > 0 && len(oldGrades) > 0 { apnsRepository := ios_apns.NewRepository(service.Repository.DB, service.Repository.Token) @@ -210,7 +210,7 @@ func sendGradesToDevice(device *model.IOSDevice, grades []model.IOSGrade, apns * Alert(alertTitle, "", alertBody). Encrypt(device.PublicKey) - log.Infof("Sending push notification to device %s", device.DeviceID) + log.WithField("DeviceID", device.DeviceID).Infof("Sending push notification") _, err := apns.SendAlertNotification(notificationPayload) diff --git a/server/backend/ios_notifications/ios_scheduling/iosSchedulingService.go b/server/backend/ios_notifications/ios_scheduling/iosSchedulingService.go index a2e60dad..1e1f9ee6 100644 --- a/server/backend/ios_notifications/ios_scheduling/iosSchedulingService.go +++ b/server/backend/ios_notifications/ios_scheduling/iosSchedulingService.go @@ -37,7 +37,7 @@ func (service *Service) HandleScheduledCron() error { devices, err := service.DevicesRepository.GetDevicesThatShouldUpdateGrades() if err != nil { - log.Errorf("Error while getting devices: %s", err) + log.WithError(err).Error("can't get devices") return err } diff --git a/server/backend/migration/20221119131300.go b/server/backend/migration/20221119131300.go index 5007c06f..2f4588dc 100644 --- a/server/backend/migration/20221119131300.go +++ b/server/backend/migration/20221119131300.go @@ -34,33 +34,29 @@ func (m TumDBMigrator) migrate20221119131300() *gormigrate.Migration { return err } - err := SafeEnumMigrate(tx, &model.Crontab{}, "type", "iosNotifications", "iosActivityReset") - - if err != nil { + if err := SafeEnumMigrate(tx, &model.Crontab{}, "type", "iosNotifications", "iosActivityReset"); err != nil { return err } var priorities []model.IOSSchedulingPriority - unmarshalErr := json.Unmarshal(iosInitialPrioritiesFile, &priorities) - - if unmarshalErr != nil { - log.Info(unmarshalErr.Error()) - return unmarshalErr + if err := json.Unmarshal(iosInitialPrioritiesFile, &priorities); err != nil { + log.WithError(err).Error("could not unmarshal json") + return err } if err := tx.Create(&priorities).Error; err != nil { - log.Info(err.Error()) + log.WithError(err).Error("could not save priority's") return err } - err = tx.Create(&model.Crontab{ + err := tx.Create(&model.Crontab{ Interval: 60, Type: null.String{NullString: sql.NullString{String: cron.IOSNotifications, Valid: true}}, }).Error if err != nil { - log.Error(err.Error()) + log.WithError(err).Error("could not create crontab") return err } diff --git a/server/backend/migration/safeEnumMigrate_test.go b/server/backend/migration/safeEnumMigrate_test.go index a8aada4c..920bcc2a 100644 --- a/server/backend/migration/safeEnumMigrate_test.go +++ b/server/backend/migration/safeEnumMigrate_test.go @@ -50,7 +50,7 @@ func isValidEnum(enum string) bool { match, err := regexp.MatchString("enum\\s*\\('\\w+'(,\\s*'\\w+')*\\);?", enum) if err != nil { - log.Errorf("error matching regex: %s", err) + log.WithError(err).Error("error matching regex") return false } diff --git a/server/backend/rpcserver.go b/server/backend/rpcserver.go index 0a4b6d00..af412a6f 100644 --- a/server/backend/rpcserver.go +++ b/server/backend/rpcserver.go @@ -40,7 +40,7 @@ type CampusServer struct { var _ pb.CampusServer = (*CampusServer)(nil) func New(db *gorm.DB) *CampusServer { - log.Println("Server starting up") + log.Trace("Server starting up") initTagRatingOptions(db) return &CampusServer{ @@ -92,7 +92,7 @@ func (s *CampusServer) GetNewsSources(ctx context.Context, _ *emptypb.Empty) (ne if err := s.db.Where("file = ?", source.Icon).First(&icon).Error; err != nil { icon = model.Files{File: 0} } - log.Info("sending news source", source.Title) + log.WithField("Title", source.Title).Info("sending news source") resp = append(resp, &pb.NewsSource{ Source: fmt.Sprintf("%d", source.Source), Title: source.Title, @@ -149,7 +149,7 @@ func (s *CampusServer) GetTopNews(ctx context.Context, _ *emptypb.Empty) (*pb.Ge if err := s.checkDevice(ctx); err != nil { return nil, err } - log.Printf("Received: get top news") + var res *model.NewsAlert err := s.db.Joins("Company").Where("NOW() between `from` and `to`").Limit(1).First(&res).Error if err != nil && !errors.Is(err, gorm.ErrRecordNotFound) {