Error logging improvements (#3768)

* Improve auto-tag error messages
* Ignore another context canceled error
* Ignore more graphql context canceled errors

internal/api/error.go

@@ -11,10 +11,11 @@ import (
 )
 
 func gqlErrorHandler(ctx context.Context, e error) *gqlerror.Error {
+	if !errors.Is(ctx.Err(), context.Canceled) {
 		// log all errors - for now just log the error message
 		// we can potentially add more context later
 		fc := graphql.GetFieldContext(ctx)
-	if fc != nil && !errors.Is(e, context.Canceled) {
+		if fc != nil {
 			logger.Errorf("%s: %v", fc.Path(), e)
 
 			// log the args in debug level
@@ -33,6 +34,7 @@ func gqlErrorHandler(ctx context.Context, e error) *gqlerror.Error {
 				}
 			})
 		}
+	}
 
 	// we may also want to transform the error message for the response
 	// for now just return the original error

internal/manager/task_autotag.go

@@ -37,7 +37,7 @@ func (j *autoTagJob) Execute(ctx context.Context, progress *job.Progress) {
 		j.autoTagSpecific(ctx, progress)
 	}
 
-	logger.Infof("Finished autotag after %s", time.Since(begin).String())
+	logger.Infof("Finished auto-tag after %s", time.Since(begin).String())
 }
 
 func (j *autoTagJob) isFileBasedAutoTag(input AutoTagMetadataInput) bool {
@@ -84,32 +84,34 @@ func (j *autoTagJob) autoTagSpecific(ctx context.Context, progress *job.Progress
 		if performerCount == 1 && performerIds[0] == wildcard {
 			performerCount, err = performerQuery.Count(ctx)
 			if err != nil {
-				return fmt.Errorf("error getting performer count: %v", err)
+				return fmt.Errorf("getting performer count: %v", err)
 			}
 		}
 		if studioCount == 1 && studioIds[0] == wildcard {
 			studioCount, err = studioQuery.Count(ctx)
 			if err != nil {
-				return fmt.Errorf("error getting studio count: %v", err)
+				return fmt.Errorf("getting studio count: %v", err)
 			}
 		}
 		if tagCount == 1 && tagIds[0] == wildcard {
 			tagCount, err = tagQuery.Count(ctx)
 			if err != nil {
-				return fmt.Errorf("error getting tag count: %v", err)
+				return fmt.Errorf("getting tag count: %v", err)
 			}
 		}
 
 		return nil
 	}); err != nil {
-		logger.Error(err.Error())
+		if !job.IsCancelled(ctx) {
+			logger.Errorf("auto-tag error: %v", err)
+		}
 		return
 	}
 
 	total := performerCount + studioCount + tagCount
 	progress.SetTotal(total)
 
-	logger.Infof("Starting autotag of %d performers, %d studios, %d tags", performerCount, studioCount, tagCount)
+	logger.Infof("Starting auto-tag of %d performers, %d studios, %d tags", performerCount, studioCount, tagCount)
 
 	j.autoTagPerformers(ctx, progress, input.Paths, performerIds)
 	j.autoTagStudios(ctx, progress, input.Paths, studioIds)
@@ -142,7 +144,7 @@ func (j *autoTagJob) autoTagPerformers(ctx context.Context, progress *job.Progre
 					PerPage: &perPage,
 				})
 				if err != nil {
-					return fmt.Errorf("error querying performers: %w", err)
+					return fmt.Errorf("querying performers: %w", err)
 				}
 			} else {
 				performerIdInt, err := strconv.Atoi(performerId)
@@ -167,11 +169,10 @@ func (j *autoTagJob) autoTagPerformers(ctx context.Context, progress *job.Progre
 
 			for _, performer := range performers {
 				if job.IsCancelled(ctx) {
-					logger.Info("Stopping due to user request")
 					return nil
 				}
 
-				if err := func() error {
+				err := func() error {
 					r := j.txnManager
 					if err := tagger.PerformerScenes(ctx, performer, paths, r.Scene); err != nil {
 						return fmt.Errorf("processing scenes: %w", err)
@@ -184,8 +185,14 @@ func (j *autoTagJob) autoTagPerformers(ctx context.Context, progress *job.Progre
 					}
 
 					return nil
-				}(); err != nil {
+				}()
-					return fmt.Errorf("error auto-tagging performer '%s': %s", performer.Name, err.Error())
+
+				if job.IsCancelled(ctx) {
+					return nil
+				}
+
+				if err != nil {
+					return fmt.Errorf("tagging performer '%s': %s", performer.Name, err.Error())
 				}
 
 				progress.Increment()
@@ -193,8 +200,12 @@ func (j *autoTagJob) autoTagPerformers(ctx context.Context, progress *job.Progre
 
 			return nil
 		}); err != nil {
-			logger.Error(err.Error())
+			logger.Errorf("auto-tag error: %v", err)
-			continue
+		}
+
+		if job.IsCancelled(ctx) {
+			logger.Info("Stopping performer auto-tag due to user request")
+			return
 		}
 	}
 }
@@ -225,17 +236,17 @@ func (j *autoTagJob) autoTagStudios(ctx context.Context, progress *job.Progress,
 					PerPage: &perPage,
 				})
 				if err != nil {
-					return fmt.Errorf("error querying studios: %v", err)
+					return fmt.Errorf("querying studios: %v", err)
 				}
 			} else {
 				studioIdInt, err := strconv.Atoi(studioId)
 				if err != nil {
-					return fmt.Errorf("error parsing studio id %s: %s", studioId, err.Error())
+					return fmt.Errorf("parsing studio id %s: %s", studioId, err.Error())
 				}
 
 				studio, err := studioQuery.Find(ctx, studioIdInt)
 				if err != nil {
-					return fmt.Errorf("error finding studio id %s: %s", studioId, err.Error())
+					return fmt.Errorf("finding studio id %s: %s", studioId, err.Error())
 				}
 
 				if studio == nil {
@@ -247,11 +258,10 @@ func (j *autoTagJob) autoTagStudios(ctx context.Context, progress *job.Progress,
 
 			for _, studio := range studios {
 				if job.IsCancelled(ctx) {
-					logger.Info("Stopping due to user request")
 					return nil
 				}
 
-				if err := func() error {
+				err := func() error {
 					aliases, err := r.Studio.GetAliases(ctx, studio.ID)
 					if err != nil {
 						return fmt.Errorf("getting studio aliases: %w", err)
@@ -268,8 +278,14 @@ func (j *autoTagJob) autoTagStudios(ctx context.Context, progress *job.Progress,
 					}
 
 					return nil
-				}(); err != nil {
+				}()
-					return fmt.Errorf("error auto-tagging studio '%s': %s", studio.Name.String, err.Error())
+
+				if job.IsCancelled(ctx) {
+					return nil
+				}
+
+				if err != nil {
+					return fmt.Errorf("tagging studio '%s': %s", studio.Name.String, err.Error())
 				}
 
 				progress.Increment()
@@ -277,8 +293,12 @@ func (j *autoTagJob) autoTagStudios(ctx context.Context, progress *job.Progress,
 
 			return nil
 		}); err != nil {
-			logger.Error(err.Error())
+			logger.Errorf("auto-tag error: %v", err)
-			continue
+		}
+
+		if job.IsCancelled(ctx) {
+			logger.Info("Stopping studio auto-tag due to user request")
+			return
 		}
 	}
 }
@@ -308,28 +328,27 @@ func (j *autoTagJob) autoTagTags(ctx context.Context, progress *job.Progress, pa
 					PerPage: &perPage,
 				})
 				if err != nil {
-					return fmt.Errorf("error querying tags: %v", err)
+					return fmt.Errorf("querying tags: %v", err)
 				}
 			} else {
 				tagIdInt, err := strconv.Atoi(tagId)
 				if err != nil {
-					return fmt.Errorf("error parsing tag id %s: %s", tagId, err.Error())
+					return fmt.Errorf("parsing tag id %s: %s", tagId, err.Error())
 				}
 
 				tag, err := tagQuery.Find(ctx, tagIdInt)
 				if err != nil {
-					return fmt.Errorf("error finding tag id %s: %s", tagId, err.Error())
+					return fmt.Errorf("finding tag id %s: %s", tagId, err.Error())
 				}
 				tags = append(tags, tag)
 			}
 
 			for _, tag := range tags {
 				if job.IsCancelled(ctx) {
-					logger.Info("Stopping due to user request")
 					return nil
 				}
 
-				if err := func() error {
+				err := func() error {
 					aliases, err := r.Tag.GetAliases(ctx, tag.ID)
 					if err != nil {
 						return fmt.Errorf("getting tag aliases: %w", err)
@@ -346,8 +365,14 @@ func (j *autoTagJob) autoTagTags(ctx context.Context, progress *job.Progress, pa
 					}
 
 					return nil
-				}(); err != nil {
+				}()
-					return fmt.Errorf("error auto-tagging tag '%s': %s", tag.Name, err.Error())
+
+				if job.IsCancelled(ctx) {
+					return nil
+				}
+
+				if err != nil {
+					return fmt.Errorf("tagging tag '%s': %s", tag.Name, err.Error())
 				}
 
 				progress.Increment()
@@ -355,8 +380,12 @@ func (j *autoTagJob) autoTagTags(ctx context.Context, progress *job.Progress, pa
 
 			return nil
 		}); err != nil {
-			logger.Error(err.Error())
+			logger.Errorf("auto-tag error: %v", err)
-			continue
+		}
+
+		if job.IsCancelled(ctx) {
+			logger.Info("Stopping tag auto-tag due to user request")
+			return
 		}
 	}
 }
@@ -488,11 +517,13 @@ func (t *autoTagFilesTask) getCount(ctx context.Context, r Repository) (int, err
 	return sceneCount + imageCount + galleryCount, nil
 }
 
-func (t *autoTagFilesTask) processScenes(ctx context.Context, r Repository) error {
+func (t *autoTagFilesTask) processScenes(ctx context.Context, r Repository) {
 	if job.IsCancelled(ctx) {
-		return nil
+		return
 	}
 
+	logger.Info("Auto-tagging scenes...")
+
 	batchSize := 1000
 
 	findFilter := models.BatchFindFilter(batchSize)
@@ -506,12 +537,16 @@ func (t *autoTagFilesTask) processScenes(ctx context.Context, r Repository) erro
 			scenes, err = scene.Query(ctx, r.Scene, sceneFilter, findFilter)
 			return err
 		}); err != nil {
-			return fmt.Errorf("querying scenes: %w", err)
+			if !job.IsCancelled(ctx) {
+				logger.Errorf("error querying scenes for auto-tag: %w", err)
+			}
+			return
 		}
 
 		for _, ss := range scenes {
 			if job.IsCancelled(ctx) {
-				return nil
+				logger.Info("Stopping auto-tag due to user request")
+				return
 			}
 
 			tt := autoTagSceneTask{
@@ -541,15 +576,15 @@ func (t *autoTagFilesTask) processScenes(ctx context.Context, r Repository) erro
 			}
 		}
 	}
-
-	return nil
 }
 
-func (t *autoTagFilesTask) processImages(ctx context.Context, r Repository) error {
+func (t *autoTagFilesTask) processImages(ctx context.Context, r Repository) {
 	if job.IsCancelled(ctx) {
-		return nil
+		return
 	}
 
+	logger.Info("Auto-tagging images...")
+
 	batchSize := 1000
 
 	findFilter := models.BatchFindFilter(batchSize)
@@ -563,12 +598,16 @@ func (t *autoTagFilesTask) processImages(ctx context.Context, r Repository) erro
 			images, err = image.Query(ctx, r.Image, imageFilter, findFilter)
 			return err
 		}); err != nil {
-			return fmt.Errorf("querying images: %w", err)
+			if !job.IsCancelled(ctx) {
+				logger.Errorf("error querying images for auto-tag: %w", err)
+			}
+			return
 		}
 
 		for _, ss := range images {
 			if job.IsCancelled(ctx) {
-				return nil
+				logger.Info("Stopping auto-tag due to user request")
+				return
 			}
 
 			tt := autoTagImageTask{
@@ -598,15 +637,15 @@ func (t *autoTagFilesTask) processImages(ctx context.Context, r Repository) erro
 			}
 		}
 	}
-
-	return nil
 }
 
-func (t *autoTagFilesTask) processGalleries(ctx context.Context, r Repository) error {
+func (t *autoTagFilesTask) processGalleries(ctx context.Context, r Repository) {
 	if job.IsCancelled(ctx) {
-		return nil
+		return
 	}
 
+	logger.Info("Auto-tagging galleries...")
+
 	batchSize := 1000
 
 	findFilter := models.BatchFindFilter(batchSize)
@@ -620,12 +659,16 @@ func (t *autoTagFilesTask) processGalleries(ctx context.Context, r Repository) e
 			galleries, _, err = r.Gallery.Query(ctx, galleryFilter, findFilter)
 			return err
 		}); err != nil {
-			return fmt.Errorf("querying galleries: %w", err)
+			if !job.IsCancelled(ctx) {
+				logger.Errorf("error querying galleries for auto-tag: %w", err)
+			}
+			return
 		}
 
 		for _, ss := range galleries {
 			if job.IsCancelled(ctx) {
-				return nil
+				logger.Info("Stopping auto-tag due to user request")
+				return
 			}
 
 			tt := autoTagGalleryTask{
@@ -655,8 +698,6 @@ func (t *autoTagFilesTask) processGalleries(ctx context.Context, r Repository) e
 			}
 		}
 	}
-
-	return nil
 }
 
 func (t *autoTagFilesTask) process(ctx context.Context) {
@@ -668,35 +709,19 @@ func (t *autoTagFilesTask) process(ctx context.Context) {
 		}
 
 		t.progress.SetTotal(total)
-		logger.Infof("Starting autotag of %d files", total)
+		logger.Infof("Starting auto-tag of %d files", total)
 
 		return nil
 	}); err != nil {
-		logger.Errorf("error getting count for autotag task: %v", err)
+		if !job.IsCancelled(ctx) {
+			logger.Errorf("error getting file count for auto-tag task: %v", err)
+		}
 		return
 	}
 
-	logger.Info("Autotagging scenes...")
+	t.processScenes(ctx, r)
-	if err := t.processScenes(ctx, r); err != nil {
+	t.processImages(ctx, r)
-		logger.Errorf("error processing scenes: %w", err)
+	t.processGalleries(ctx, r)
-		return
-	}
-
-	logger.Info("Autotagging images...")
-	if err := t.processImages(ctx, r); err != nil {
-		logger.Errorf("error processing images: %w", err)
-		return
-	}
-
-	logger.Info("Autotagging galleries...")
-	if err := t.processGalleries(ctx, r); err != nil {
-		logger.Errorf("error processing galleries: %w", err)
-		return
-	}
-
-	if job.IsCancelled(ctx) {
-		logger.Info("Stopping due to user request")
-	}
 }
 
 type autoTagSceneTask struct {
@@ -721,23 +746,25 @@ func (t *autoTagSceneTask) Start(ctx context.Context, wg *sync.WaitGroup) {
 
 		if t.performers {
 			if err := autotag.ScenePerformers(ctx, t.scene, r.Scene, r.Performer, t.cache); err != nil {
-				return fmt.Errorf("error tagging scene performers for %s: %v", t.scene.DisplayName(), err)
+				return fmt.Errorf("tagging scene performers for %s: %v", t.scene.DisplayName(), err)
 			}
 		}
 		if t.studios {
 			if err := autotag.SceneStudios(ctx, t.scene, r.Scene, r.Studio, t.cache); err != nil {
-				return fmt.Errorf("error tagging scene studio for %s: %v", t.scene.DisplayName(), err)
+				return fmt.Errorf("tagging scene studio for %s: %v", t.scene.DisplayName(), err)
 			}
 		}
 		if t.tags {
 			if err := autotag.SceneTags(ctx, t.scene, r.Scene, r.Tag, t.cache); err != nil {
-				return fmt.Errorf("error tagging scene tags for %s: %v", t.scene.DisplayName(), err)
+				return fmt.Errorf("tagging scene tags for %s: %v", t.scene.DisplayName(), err)
 			}
 		}
 
 		return nil
 	}); err != nil {
-		logger.Error(err.Error())
+		if !job.IsCancelled(ctx) {
+			logger.Errorf("auto-tag error: %v", err)
+		}
 	}
 }
 
@@ -758,23 +785,25 @@ func (t *autoTagImageTask) Start(ctx context.Context, wg *sync.WaitGroup) {
 	if err := t.txnManager.WithTxn(ctx, func(ctx context.Context) error {
 		if t.performers {
 			if err := autotag.ImagePerformers(ctx, t.image, r.Image, r.Performer, t.cache); err != nil {
-				return fmt.Errorf("error tagging image performers for %s: %v", t.image.DisplayName(), err)
+				return fmt.Errorf("tagging image performers for %s: %v", t.image.DisplayName(), err)
 			}
 		}
 		if t.studios {
 			if err := autotag.ImageStudios(ctx, t.image, r.Image, r.Studio, t.cache); err != nil {
-				return fmt.Errorf("error tagging image studio for %s: %v", t.image.DisplayName(), err)
+				return fmt.Errorf("tagging image studio for %s: %v", t.image.DisplayName(), err)
 			}
 		}
 		if t.tags {
 			if err := autotag.ImageTags(ctx, t.image, r.Image, r.Tag, t.cache); err != nil {
-				return fmt.Errorf("error tagging image tags for %s: %v", t.image.DisplayName(), err)
+				return fmt.Errorf("tagging image tags for %s: %v", t.image.DisplayName(), err)
 			}
 		}
 
 		return nil
 	}); err != nil {
-		logger.Error(err.Error())
+		if !job.IsCancelled(ctx) {
+			logger.Errorf("auto-tag error: %v", err)
+		}
 	}
 }
 
@@ -795,22 +824,24 @@ func (t *autoTagGalleryTask) Start(ctx context.Context, wg *sync.WaitGroup) {
 	if err := t.txnManager.WithTxn(ctx, func(ctx context.Context) error {
 		if t.performers {
 			if err := autotag.GalleryPerformers(ctx, t.gallery, r.Gallery, r.Performer, t.cache); err != nil {
-				return fmt.Errorf("error tagging gallery performers for %s: %v", t.gallery.DisplayName(), err)
+				return fmt.Errorf("tagging gallery performers for %s: %v", t.gallery.DisplayName(), err)
 			}
 		}
 		if t.studios {
 			if err := autotag.GalleryStudios(ctx, t.gallery, r.Gallery, r.Studio, t.cache); err != nil {
-				return fmt.Errorf("error tagging gallery studio for %s: %v", t.gallery.DisplayName(), err)
+				return fmt.Errorf("tagging gallery studio for %s: %v", t.gallery.DisplayName(), err)
 			}
 		}
 		if t.tags {
 			if err := autotag.GalleryTags(ctx, t.gallery, r.Gallery, r.Tag, t.cache); err != nil {
-				return fmt.Errorf("error tagging gallery tags for %s: %v", t.gallery.DisplayName(), err)
+				return fmt.Errorf("tagging gallery tags for %s: %v", t.gallery.DisplayName(), err)
 			}
 		}
 
 		return nil
 	}); err != nil {
-		logger.Error(err.Error())
+		if !job.IsCancelled(ctx) {
+			logger.Errorf("auto-tag error: %v", err)
+		}
 	}
 }

pkg/scraper/stashbox/stash_box.go

@@ -664,7 +664,7 @@ func performerFragmentToScrapedScenePerformer(p graphql.PerformerFragment) *mode
 
 func getFirstImage(ctx context.Context, client *http.Client, images []*graphql.ImageFragment) *string {
 	ret, err := fetchImage(ctx, client, images[0].URL)
-	if err != nil {
+	if err != nil && !errors.Is(err, context.Canceled) {
 		logger.Warnf("Error fetching image %s: %s", images[0].URL, err.Error())
 	}