Logs: Tweak messages and log levels for improved readability

internal/api/album.go

@@ -526,10 +526,10 @@ func DownloadAlbum(router *gin.RouterGroup) {
 				}
 				log.Infof("download: added %s as %s", txt.Quote(file.FileName), txt.Quote(alias))
 			} else {
-				log.Errorf("download: file %s is missing", txt.Quote(file.FileName))
+				log.Errorf("download: failed finding %s", txt.Quote(file.FileName))
 			}
 		}
 
-		log.Infof("download: album zip %s created in %s", txt.Quote(zipFileName), time.Since(start))
+		log.Infof("download: created %s in %s", txt.Quote(zipFileName), time.Since(start))
 	})
 }

internal/api/api.go

@@ -49,6 +49,12 @@ func logError(prefix string, err error) {
 	}
 }
 
+func logWarn(prefix string, err error) {
+	if err != nil {
+		log.Warnf("%s: %s", prefix, err.Error())
+	}
+}
+
 func UpdateClientConfig() {
 	conf := service.Config()
 

internal/api/batch.go

@@ -66,10 +66,10 @@ func BatchPhotosArchive(router *gin.RouterGroup) {
 		}
 
 		// Update precalculated photo and file counts.
-		logError("photos", entity.UpdatePhotoCounts())
+		logWarn("index", entity.UpdateCounts())
 
 		// Update album, subject, and label cover thumbs.
-		logError("photos", query.UpdateCovers())
+		logWarn("index", query.UpdateCovers())
 
 		UpdateClientConfig()
 
@@ -128,10 +128,10 @@ func BatchPhotosRestore(router *gin.RouterGroup) {
 		}
 
 		// Update precalculated photo and file counts.
-		logError("photos", entity.UpdatePhotoCounts())
+		logWarn("index", entity.UpdateCounts())
 
 		// Update album, subject, and label cover thumbs.
-		logError("photos", query.UpdateCovers())
+		logWarn("index", query.UpdateCovers())
 
 		UpdateClientConfig()
 
@@ -264,7 +264,7 @@ func BatchPhotosPrivate(router *gin.RouterGroup) {
 		}
 
 		// Update precalculated photo and file counts.
-		logError("photos", entity.UpdatePhotoCounts())
+		logWarn("index", entity.UpdateCounts())
 
 		if photos, err := query.PhotoSelection(f); err == nil {
 			for _, p := range photos {
@@ -382,7 +382,7 @@ func BatchPhotosDelete(router *gin.RouterGroup) {
 		// Any photos deleted?
 		if len(deleted) > 0 {
 			// Update precalculated photo and file counts.
-			logError("photos", entity.UpdatePhotoCounts())
+			logWarn("index", entity.UpdateCounts())
 
 			UpdateClientConfig()
 

internal/api/import.go

@@ -113,7 +113,7 @@ func StartImport(router *gin.RouterGroup) {
 
 		// Update album, label, and subject cover thumbs.
 		if err := query.UpdateCovers(); err != nil {
-			log.Errorf("import: %s (update covers)", err)
+			log.Warnf("index: %s (update covers)", err)
 		}
 
 		c.JSON(http.StatusOK, i18n.Response{Code: http.StatusOK, Msg: msg})

internal/api/zip.go

@@ -126,7 +126,7 @@ func CreateZip(router *gin.RouterGroup) {
 
 		elapsed := int(time.Since(start).Seconds())
 
-		log.Infof("download: zip %s created in %s", txt.Quote(zipBaseName), time.Since(start))
+		log.Infof("download: created %s in %s", txt.Quote(zipBaseName), time.Since(start))
 
 		c.JSON(http.StatusOK, gin.H{"code": http.StatusOK, "message": i18n.Msg(i18n.MsgZipCreatedIn, elapsed), "filename": zipBaseName})
 	})

internal/commands/cleanup.go

@@ -4,6 +4,8 @@ import (
 	"context"
 	"time"
 
+	"github.com/dustin/go-humanize/english"
+
 	"github.com/urfave/cli"
 
 	"github.com/photoprism/photoprism/internal/config"
@@ -55,9 +57,7 @@ func cleanUpAction(ctx *cli.Context) error {
 	if thumbs, orphans, err := w.Start(opt); err != nil {
 		return err
 	} else {
-		elapsed := time.Since(start)
+		log.Infof("cleanup: removed %s and %s [%s]", english.Plural(orphans, "index entry", "index entries"), english.Plural(thumbs, "thumbnail", "thumbnails"), time.Since(start))
-
-		log.Infof("cleanup: removed %d index entries and %d orphan thumbnails in %s", orphans, thumbs, elapsed)
 	}
 
 	conf.Shutdown()

internal/commands/faces.go

@@ -6,6 +6,8 @@ import (
 	"strings"
 	"time"
 
+	"github.com/dustin/go-humanize/english"
+
 	"github.com/manifoldco/promptui"
 	"github.com/urfave/cli"
 
@@ -270,13 +272,13 @@ func facesIndexAction(ctx *cli.Context) error {
 		if files, photos, err := w.Start(opt); err != nil {
 			log.Error(err)
 		} else if len(files) > 0 || len(photos) > 0 {
-			log.Infof("purge: removed %d files and %d photos", len(files), len(photos))
+			log.Infof("purge: removed %s and %s", english.Plural(len(files), "file", "files"), english.Plural(len(photos), "photo", "photos"))
 		}
 	}
 
 	elapsed := time.Since(start)
 
-	log.Infof("indexed %d files in %s", len(indexed), elapsed)
+	log.Infof("indexed %d files [%s]", len(indexed), elapsed)
 
 	conf.Shutdown()
 
@@ -341,7 +343,7 @@ func facesOptimizeAction(ctx *cli.Context) error {
 	} else {
 		elapsed := time.Since(start)
 
-		log.Infof("%d face clusters merged in %s", res.Merged, elapsed)
+		log.Infof("%d face clusters merged [%s]", res.Merged, elapsed)
 	}
 
 	conf.Shutdown()

internal/commands/index.go

@@ -6,6 +6,8 @@ import (
 	"strings"
 	"time"
 
+	"github.com/dustin/go-humanize/english"
+
 	"github.com/urfave/cli"
 
 	"github.com/photoprism/photoprism/internal/config"
@@ -78,6 +80,7 @@ func indexAction(ctx *cli.Context) error {
 	}
 
 	if w := service.Purge(); w != nil {
+		purgeStart := time.Now()
 		opt := photoprism.PurgeOptions{
 			Path:   subPath,
 			Ignore: indexed,
@@ -86,11 +89,12 @@ func indexAction(ctx *cli.Context) error {
 		if files, photos, err := w.Start(opt); err != nil {
 			log.Error(err)
 		} else if len(files) > 0 || len(photos) > 0 {
-			log.Infof("purge: removed %d files and %d photos", len(files), len(photos))
+			log.Infof("purge: removed %s and %s [%s]", english.Plural(len(files), "file", "files"), english.Plural(len(photos), "photo", "photos"), time.Since(purgeStart))
 		}
 	}
 
 	if ctx.Bool("cleanup") {
+		cleanupStart := time.Now()
 		w := service.CleanUp()
 
 		opt := photoprism.CleanUpOptions{
@@ -100,13 +104,13 @@ func indexAction(ctx *cli.Context) error {
 		if thumbs, orphans, err := w.Start(opt); err != nil {
 			return err
 		} else {
-			log.Infof("cleanup: removed %d index entries and %d orphan thumbnails", orphans, thumbs)
+			log.Infof("cleanup: removed %s and %s [%s]", english.Plural(orphans, "index entry", "index entries"), english.Plural(thumbs, "thumbnail", "thumbnails"), time.Since(cleanupStart))
 		}
 	}
 
 	elapsed := time.Since(start)
 
-	log.Infof("indexed %d files in %s", len(indexed), elapsed)
+	log.Infof("indexed %d files [%s]", len(indexed), elapsed)
 
 	conf.Shutdown()
 

internal/commands/index_test.go

@@ -49,9 +49,8 @@ func TestIndexCommand(t *testing.T) {
 		assert.Contains(t, output, "indexing originals")
 		assert.Contains(t, output, "classify: loading labels")
 		assert.Contains(t, output, "index: no .ppignore file found")
-		assert.Contains(t, output, "searching index for unassigned primary files")
+		assert.Contains(t, output, "index: updating primary files")
-		assert.Contains(t, output, "searching index for hidden media files")
+		assert.Contains(t, output, "index: flagging hidden files")
-		assert.Contains(t, output, "updating photo counts")
 	} else {
 		t.Fatal("log output missing")
 	}

internal/commands/migrate.go

@@ -35,7 +35,7 @@ func migrateAction(ctx *cli.Context) error {
 
 	elapsed := time.Since(start)
 
-	log.Infof("database migration completed in %s", elapsed)
+	log.Infof("database migration completed [%s]", elapsed)
 
 	conf.Shutdown()
 

internal/commands/purge.go

@@ -6,6 +6,8 @@ import (
 	"strings"
 	"time"
 
+	"github.com/dustin/go-humanize/english"
+
 	"github.com/urfave/cli"
 
 	"github.com/photoprism/photoprism/internal/config"
@@ -76,7 +78,7 @@ func purgeAction(ctx *cli.Context) error {
 	} else {
 		elapsed := time.Since(start)
 
-		log.Infof("purge: removed %d files and %d photos in %s", len(files), len(photos), elapsed)
+		log.Infof("purge: removed %s and %s [%s]", english.Plural(len(files), "file", "files"), english.Plural(len(photos), "photo", "photos"), elapsed)
 	}
 
 	conf.Shutdown()

internal/commands/resample.go

@@ -46,7 +46,7 @@ func resampleAction(ctx *cli.Context) error {
 
 	elapsed := time.Since(start)
 
-	log.Infof("thumbnails created in %s", elapsed)
+	log.Infof("thumbnails created [%s]", elapsed)
 
 	return nil
 }

internal/commands/reset.go

@@ -57,7 +57,7 @@ func resetAction(ctx *cli.Context) error {
 			entity.Admin.InitPassword(conf.AdminPassword())
 		}
 
-		log.Infof("database reset completed in %s", time.Since(start))
+		log.Infof("database reset completed [%s]", time.Since(start))
 	} else {
 		log.Infof("keeping index database")
 	}
@@ -89,7 +89,7 @@ func resetAction(ctx *cli.Context) error {
 
 			fmt.Println("")
 
-			log.Infof("removed json files in %s", time.Since(start))
+			log.Infof("removed json files [%s]", time.Since(start))
 		} else {
 			log.Infof("no json files found")
 		}
@@ -124,7 +124,7 @@ func resetAction(ctx *cli.Context) error {
 
 			fmt.Println("")
 
-			log.Infof("removed files in %s", time.Since(start))
+			log.Infof("removed files [%s]", time.Since(start))
 		} else {
 			log.Infof("no metadata backups found for removal")
 		}
@@ -159,7 +159,7 @@ func resetAction(ctx *cli.Context) error {
 
 			fmt.Println("")
 
-			log.Infof("removed files in %s", time.Since(start))
+			log.Infof("removed files [%s]", time.Since(start))
 		} else {
 			log.Infof("no album backups found for removal")
 		}

internal/commands/restore.go

@@ -212,7 +212,7 @@ func restoreAction(ctx *cli.Context) error {
 
 	elapsed := time.Since(start)
 
-	log.Infof("backup restored in %s", elapsed)
+	log.Infof("backup restored [%s]", elapsed)
 
 	conf.Shutdown()
 

internal/entity/counts.go

@@ -46,8 +46,8 @@ func LabelCounts() LabelPhotoCounts {
 	return result
 }
 
-// UpdatePlacesPhotoCounts updates the places photo counts.
+// UpdatePlacesCounts updates the places photo counts.
-func UpdatePlacesPhotoCounts() (err error) {
+func UpdatePlacesCounts() (err error) {
 	start := time.Now()
 
 	// Update places.
@@ -62,7 +62,7 @@ func UpdatePlacesPhotoCounts() (err error) {
 		return res.Error
 	}
 
-	log.Debugf("counts: %s updated [%s]", english.Plural(int(res.RowsAffected), "place", "places"), time.Since(start))
+	log.Debugf("counts: updated %s [%s]", english.Plural(int(res.RowsAffected), "place", "places"), time.Since(start))
 
 	return nil
 }
@@ -114,13 +114,13 @@ func UpdateSubjectCounts() (err error) {
 		return res.Error
 	}
 
-	log.Debugf("counts: %s updated [%s]", english.Plural(int(res.RowsAffected), "subject", "subjects"), time.Since(start))
+	log.Debugf("counts: updated %s [%s]", english.Plural(int(res.RowsAffected), "subject", "subjects"), time.Since(start))
 
 	return nil
 }
 
-// UpdateLabelPhotoCounts updates the label photo counts.
+// UpdateLabelCounts updates the label photo counts.
-func UpdateLabelPhotoCounts() (err error) {
+func UpdateLabelCounts() (err error) {
 	start := time.Now()
 	var res *gorm.DB
 	if IsDialect(MySQL) {
@@ -166,14 +166,16 @@ func UpdateLabelPhotoCounts() (err error) {
 		return res.Error
 	}
 
-	log.Debugf("counts: %s updated [%s]", english.Plural(int(res.RowsAffected), "label", "labels"), time.Since(start))
+	log.Debugf("counts: updated %s [%s]", english.Plural(int(res.RowsAffected), "label", "labels"), time.Since(start))
 
 	return nil
 }
 
-// UpdatePhotoCounts updates precalculated photo and file counts.
+// UpdateCounts updates precalculated photo and file counts.
-func UpdatePhotoCounts() (err error) {
+func UpdateCounts() (err error) {
-	if err = UpdatePlacesPhotoCounts(); err != nil {
+	log.Info("index: updating counts")
+
+	if err = UpdatePlacesCounts(); err != nil {
 		if strings.Contains(err.Error(), "Error 1054") {
 			log.Errorf("counts: failed updating places, potentially incompatible database version")
 			log.Errorf("%s see https://jira.mariadb.org/browse/MDEV-25362", err)
@@ -193,7 +195,7 @@ func UpdatePhotoCounts() (err error) {
 		return err
 	}
 
-	if err = UpdateLabelPhotoCounts(); err != nil {
+	if err = UpdateLabelCounts(); err != nil {
 		return err
 	}
 

internal/entity/counts_test.go

@@ -17,7 +17,7 @@ func TestLabelCounts(t *testing.T) {
 }
 
 func TestUpdatePhotoCounts(t *testing.T) {
-	err := UpdatePhotoCounts()
+	err := UpdateCounts()
 
 	if err != nil {
 		t.Fatal(err)

internal/entity/file.go

@@ -262,7 +262,7 @@ func (m *File) ReplaceHash(newHash string) error {
 		if res := UnscopedDb().Model(entity).Where("thumb = ?", oldHash).UpdateColumn("thumb", newHash); res.Error != nil {
 			return res.Error
 		} else if res.RowsAffected > 0 {
-			log.Infof("%s: %s updated [%s]", name, english.Plural(int(res.RowsAffected), "cover", "covers"), time.Since(start))
+			log.Infof("%s: updated %s [%s]", name, english.Plural(int(res.RowsAffected), "cover", "covers"), time.Since(start))
 		}
 	}
 

internal/entity/photo.go

@@ -187,8 +187,8 @@ func SavePhotoForm(model Photo, form form.Photo) error {
 	}
 
 	// Update precalculated photo and file counts.
-	if err := UpdatePhotoCounts(); err != nil {
+	if err := UpdateCounts(); err != nil {
-		log.Errorf("photo: %s", err)
+		log.Warnf("index: %s (update counts)", err)
 	}
 
 	return nil
@@ -315,8 +315,8 @@ func (m *Photo) SaveLabels() error {
 	}
 
 	// Update precalculated photo and file counts.
-	if err := UpdatePhotoCounts(); err != nil {
+	if err := UpdateCounts(); err != nil {
-		log.Errorf("photo: %s", err)
+		log.Warnf("index: %s (update counts)", err)
 	}
 
 	return nil
@@ -1041,8 +1041,8 @@ func (m *Photo) Approve() error {
 	}
 
 	// Update precalculated photo and file counts.
-	if err := UpdatePhotoCounts(); err != nil {
+	if err := UpdateCounts(); err != nil {
-		log.Errorf("photo: %s", err)
+		log.Warnf("index: %s (update counts)", err)
 	}
 
 	event.Publish("count.review", event.Data{

internal/photoprism/cleanup.go

@@ -91,12 +91,12 @@ func (w *CleanUp) Start(opt CleanUpOptions) (thumbs int, orphans int, err error)
 			// Do nothing.
 		} else if opt.Dry {
 			thumbs++
-			log.Debugf("cleanup: orphan thumbnail %s would be removed", logName)
+			log.Debugf("cleanup: thumbnail %s would be removed", logName)
 		} else if err := os.Remove(fileName); err != nil {
 			log.Warnf("cleanup: %s in %s", err, logName)
 		} else {
 			thumbs++
-			log.Debugf("cleanup: removed orphan thumbnail %s", logName)
+			log.Debugf("cleanup: removed thumbnail %s", logName)
 		}
 
 		return nil
@@ -136,32 +136,28 @@ func (w *CleanUp) Start(opt CleanUpOptions) (thumbs int, orphans int, err error)
 	// Remove orphan index entries.
 	if opt.Dry {
 		if files, err := query.OrphanFiles(); err != nil {
-			log.Errorf("cleanup: %s (find orphan files)", err)
+			log.Errorf("index: %s (find orphan files)", err)
 		} else if l := len(files); l > 0 {
-			log.Infof("cleanup: found %s", english.Plural(l, "orphan file", "orphan files"))
+			log.Infof("index: found %s", english.Plural(l, "orphan file", "orphan files"))
 		} else {
-			log.Infof("cleanup: found no orphan files")
+			log.Infof("index: found no orphan files")
 		}
 	} else {
 		if err := query.PurgeOrphans(); err != nil {
-			log.Errorf("cleanup: %s (remove orphans)", err)
+			log.Errorf("index: %s (remove orphans)", err)
 		}
 	}
 
 	// Only update counts if anything was deleted.
 	if len(deleted) > 0 {
-		log.Info("updating photo counts")
-
 		// Update precalculated photo and file counts.
-		if err := entity.UpdatePhotoCounts(); err != nil {
+		if err := entity.UpdateCounts(); err != nil {
-			log.Errorf("cleanup: %s (update counts)", err)
+			log.Warnf("index: %s (update counts)", err)
 		}
 
-		log.Info("updating cover thumbs")
-
 		// Update album, subject, and label cover thumbs.
 		if err := query.UpdateCovers(); err != nil {
-			log.Errorf("cleanup: %s (update covers)", err)
+			log.Warnf("index: %s (update covers)", err)
 		}
 
 		// Show success notification.

internal/photoprism/faces.go

@@ -125,9 +125,9 @@ func (w *Faces) Start(opt FacesOptions) (err error) {
 
 	// Log face matching results.
 	if matches.Updated > 0 {
-		log.Infof("faces: %d markers updated, %d faces recognized, %d unknown [%s]", matches.Updated, matches.Recognized, matches.Unknown, time.Since(start))
+		log.Infof("faces: updated %d markers, recognized %d faces, %d unknown [%s]", matches.Updated, matches.Recognized, matches.Unknown, time.Since(start))
 	} else {
-		log.Debugf("faces: %d markers updated, %d faces recognized, %d unknown [%s]", matches.Updated, matches.Recognized, matches.Unknown, time.Since(start))
+		log.Debugf("faces: updated %d markers, recognized %d faces, %d unknown [%s]", matches.Updated, matches.Recognized, matches.Unknown, time.Since(start))
 	}
 
 	// Remove unused people.

internal/photoprism/import.go

@@ -253,8 +253,8 @@ func (imp *Import) Start(opt ImportOptions) fs.Done {
 		}
 
 		// Update photo counts and visibilities.
-		if err := entity.UpdatePhotoCounts(); err != nil {
+		if err := entity.UpdateCounts(); err != nil {
-			log.Errorf("import: %s (update counts)", err)
+			log.Warnf("index: %s (update counts)", err)
 		}
 	}
 

internal/photoprism/import_worker.go

@@ -40,7 +40,7 @@ func ImportWorker(jobs <-chan ImportJob) {
 			} else if err := related.Main.ReadExifToolJson(); err != nil {
 				log.Errorf("import: %s in %s (read metadata)", txt.Quote(err.Error()), txt.Quote(related.Main.BaseName()))
 			} else {
-				log.Debugf("import: %s created", filepath.Base(jsonName))
+				log.Debugf("import: created %s", filepath.Base(jsonName))
 			}
 		}
 
@@ -122,7 +122,7 @@ func ImportWorker(jobs <-chan ImportJob) {
 				if jsonName, err := imp.convert.ToJson(f); err != nil {
 					log.Debugf("import: %s in %s (extract metadata)", txt.Quote(err.Error()), txt.Quote(f.BaseName()))
 				} else {
-					log.Debugf("import: %s created", filepath.Base(jsonName))
+					log.Debugf("import: created %s", filepath.Base(jsonName))
 				}
 			}
 
@@ -131,7 +131,7 @@ func ImportWorker(jobs <-chan ImportJob) {
 					log.Errorf("import: %s in %s (convert to jpeg)", err.Error(), txt.Quote(fs.RelName(destMainFileName, imp.originalsPath())))
 					continue
 				} else {
-					log.Debugf("import: %s created", txt.Quote(jpegFile.BaseName()))
+					log.Debugf("import: created %s", txt.Quote(jpegFile.BaseName()))
 				}
 			}
 
@@ -202,7 +202,7 @@ func ImportWorker(jobs <-chan ImportJob) {
 					if jsonName, err := imp.convert.ToJson(f); err != nil {
 						log.Debugf("import: %s in %s (extract metadata)", txt.Quote(err.Error()), txt.Quote(f.BaseName()))
 					} else {
-						log.Debugf("import: %s created", filepath.Base(jsonName))
+						log.Debugf("import: created %s", filepath.Base(jsonName))
 					}
 				}
 

internal/photoprism/index.go

@@ -261,8 +261,8 @@ func (ind *Index) Start(opt IndexOptions) fs.Done {
 		})
 
 		// Update precalculated photo and file counts.
-		if err := entity.UpdatePhotoCounts(); err != nil {
+		if err := entity.UpdateCounts(); err != nil {
-			log.Errorf("index: %s (update counts)", err)
+			log.Warnf("index: %s (update counts)", err)
 		}
 	} else {
 		log.Infof("index: no new or modified files")

internal/photoprism/index_related.go

@@ -31,7 +31,7 @@ func IndexMain(related *RelatedFiles, ind *Index, opt IndexOptions) (result Inde
 		if jsonName, err := ind.convert.ToJson(f); err != nil {
 			log.Debugf("index: %s in %s (extract metadata)", txt.Quote(err.Error()), txt.Quote(f.BaseName()))
 		} else {
-			log.Debugf("index: %s created", filepath.Base(jsonName))
+			log.Debugf("index: created %s", filepath.Base(jsonName))
 		}
 	}
 
@@ -42,7 +42,7 @@ func IndexMain(related *RelatedFiles, ind *Index, opt IndexOptions) (result Inde
 
 			return result
 		} else {
-			log.Debugf("index: %s created", txt.Quote(jpegFile.BaseName()))
+			log.Debugf("index: created %s", txt.Quote(jpegFile.BaseName()))
 
 			if err := jpegFile.ResampleDefault(ind.thumbPath(), false); err != nil {
 				result.Err = fmt.Errorf("index: failed creating thumbs for %s (%s)", txt.Quote(f.BaseName()), err.Error())
@@ -112,7 +112,7 @@ func IndexRelated(related RelatedFiles, ind *Index, opt IndexOptions) (result In
 			if jsonName, err := ind.convert.ToJson(f); err != nil {
 				log.Debugf("index: %s in %s (extract metadata)", txt.Quote(err.Error()), txt.Quote(f.BaseName()))
 			} else {
-				log.Debugf("index: %s created", filepath.Base(jsonName))
+				log.Debugf("index: created %s", filepath.Base(jsonName))
 			}
 		}
 
@@ -123,7 +123,7 @@ func IndexRelated(related RelatedFiles, ind *Index, opt IndexOptions) (result In
 
 				return result
 			} else {
-				log.Debugf("index: %s created", txt.Quote(jpegFile.BaseName()))
+				log.Debugf("index: created %s", txt.Quote(jpegFile.BaseName()))
 
 				if err := jpegFile.ResampleDefault(ind.thumbPath(), false); err != nil {
 					result.Err = fmt.Errorf("index: failed creating thumbs for %s (%s)", txt.Quote(f.BaseName()), err.Error())

internal/photoprism/mediafile.go

@@ -14,6 +14,8 @@ import (
 	"sync"
 	"time"
 
+	"github.com/dustin/go-humanize/english"
+
 	"github.com/disintegration/imaging"
 	"github.com/djherbis/times"
 
@@ -926,11 +928,9 @@ func (m *MediaFile) ResampleDefault(thumbPath string, force bool) (err error) {
 	defer func() {
 		switch count {
 		case 0:
-			log.Debug(capture.Time(start, fmt.Sprintf("media: no new thumbs created for %s", m.BasePrefix(false))))
+			log.Debug(capture.Time(start, fmt.Sprintf("media: no new thumbnails created for %s", m.BasePrefix(false))))
-		case 1:
-			log.Info(capture.Time(start, fmt.Sprintf("media: one thumbnail created for %s", m.BasePrefix(false))))
 		default:
-			log.Info(capture.Time(start, fmt.Sprintf("media: %d thumbs created for %s", count, m.BasePrefix(false))))
+			log.Info(capture.Time(start, fmt.Sprintf("media: created %s for %s", english.Plural(count, "thumbnail", "thumbnails"), m.BasePrefix(false))))
 		}
 	}()
 

internal/photoprism/moments.go

@@ -55,10 +55,10 @@ func (w *Moments) Start() (err error) {
 		threshold = int(math.Log2(float64(indexSize))) + 1
 	}
 
-	log.Debugf("moments: index contains %d photos and %d videos, using threshold %d", counts.Photos, counts.Videos, threshold)
+	log.Debugf("moments: analyzing %d photos / %d videos, using threshold %d", counts.Photos, counts.Videos, threshold)
 
 	if indexSize < threshold {
-		log.Debugf("moments: nothing to do, index size is smaller than threshold")
+		log.Debugf("moments: not enough files")
 
 		return nil
 	}

internal/photoprism/purge.go

@@ -241,14 +241,10 @@ func (w *Purge) Start(opt PurgeOptions) (purgedFiles map[string]bool, purgedPhot
 		time.Sleep(50 * time.Millisecond)
 	}
 
-	log.Info("searching index for unassigned primary files")
-
 	if err := query.FixPrimaries(); err != nil {
-		log.Errorf("purge: %s (fix primary files)", err.Error())
+		log.Errorf("index: %s (update primary files)", err.Error())
 	}
 
-	log.Info("searching index for hidden media files")
-
 	// Set photo quality scores to -1 if files are missing.
 	if err := query.ResetPhotoQuality(); err != nil {
 		return purgedFiles, purgedPhotos, err
@@ -257,33 +253,31 @@ func (w *Purge) Start(opt PurgeOptions) (purgedFiles map[string]bool, purgedPhot
 	// Remove orphan index entries.
 	if opt.Dry {
 		if files, err := query.OrphanFiles(); err != nil {
-			log.Errorf("purge: %s (find orphan files)", err)
+			log.Errorf("index: %s (find orphan files)", err)
 		} else if l := len(files); l > 0 {
-			log.Infof("purge: found %s", english.Plural(l, "orphan file", "orphan files"))
+			log.Infof("index: found %s", english.Plural(l, "orphan file", "orphan files"))
 		} else {
-			log.Infof("purge: found no orphan files")
+			log.Infof("index: found no orphan files")
 		}
 	} else {
 		if err := query.PurgeOrphans(); err != nil {
-			log.Errorf("purge: %s (remove orphans)", err)
+			log.Errorf("index: %s (remove orphans)", err)
 		}
 	}
 
 	// Hide missing album contents.
 	if err := query.UpdateMissingAlbumEntries(); err != nil {
-		log.Errorf("purge: %s (album entries)", err)
+		log.Errorf("index: %s (update album entries)", err)
 	}
 
 	// Update precalculated photo and file counts.
-	log.Info("updating photo counts")
+	if err := entity.UpdateCounts(); err != nil {
-	if err := entity.UpdatePhotoCounts(); err != nil {
+		log.Warnf("index: %s (update counts)", err)
-		log.Errorf("purge: %s (update counts)", err)
 	}
 
 	// Update album, subject, and label cover thumbs.
-	log.Info("updating cover thumbs")
 	if err := query.UpdateCovers(); err != nil {
-		log.Errorf("purge: %s (update covers)", err)
+		log.Warnf("index: %s (update covers)", err)
 	}
 
 	return purgedFiles, purgedPhotos, nil

internal/query/covers.go

@@ -46,7 +46,7 @@ func UpdateAlbumDefaultCovers() (err error) {
 	err = res.Error
 
 	if err == nil {
-		log.Debugf("covers: %s updated [%s]", english.Plural(int(res.RowsAffected), "album", "albums"), time.Since(start))
+		log.Debugf("covers: updated %s [%s]", english.Plural(int(res.RowsAffected), "album", "albums"), time.Since(start))
 	} else if strings.Contains(err.Error(), "Error 1054") {
 		log.Errorf("covers: failed updating albums, potentially incompatible database version")
 		log.Errorf("%s see https://jira.mariadb.org/browse/MDEV-25362", err)
@@ -91,7 +91,7 @@ func UpdateAlbumFolderCovers() (err error) {
 	err = res.Error
 
 	if err == nil {
-		log.Debugf("covers: %s updated [%s]", english.Plural(int(res.RowsAffected), "folder", "folders"), time.Since(start))
+		log.Debugf("covers: updated %s [%s]", english.Plural(int(res.RowsAffected), "folder", "folders"), time.Since(start))
 	} else if strings.Contains(err.Error(), "Error 1054") {
 		log.Errorf("covers: failed updating folders, potentially incompatible database version")
 		log.Errorf("%s see https://jira.mariadb.org/browse/MDEV-25362", err)
@@ -136,7 +136,7 @@ func UpdateAlbumMonthCovers() (err error) {
 	err = res.Error
 
 	if err == nil {
-		log.Debugf("covers: %s updated [%s]", english.Plural(int(res.RowsAffected), "month", "months"), time.Since(start))
+		log.Debugf("covers: updated %s [%s]", english.Plural(int(res.RowsAffected), "month", "months"), time.Since(start))
 	} else if strings.Contains(err.Error(), "Error 1054") {
 		log.Errorf("covers: failed updating calendar, potentially incompatible database version")
 		log.Errorf("%s see https://jira.mariadb.org/browse/MDEV-25362", err)
@@ -220,7 +220,7 @@ func UpdateLabelCovers() (err error) {
 	err = res.Error
 
 	if err == nil {
-		log.Debugf("covers: %s updated [%s]", english.Plural(int(res.RowsAffected), "label", "labels"), time.Since(start))
+		log.Debugf("covers: updated %s [%s]", english.Plural(int(res.RowsAffected), "label", "labels"), time.Since(start))
 	} else if strings.Contains(err.Error(), "Error 1054") {
 		log.Errorf("covers: failed updating labels, potentially incompatible database version")
 		log.Errorf("%s see https://jira.mariadb.org/browse/MDEV-25362", err)
@@ -266,7 +266,7 @@ func UpdateSubjectCovers() (err error) {
 	err = res.Error
 
 	if err == nil {
-		log.Debugf("covers: %s updated [%s]", english.Plural(int(res.RowsAffected), "subject", "subjects"), time.Since(start))
+		log.Debugf("covers: updated %s [%s]", english.Plural(int(res.RowsAffected), "subject", "subjects"), time.Since(start))
 	} else if strings.Contains(err.Error(), "Error 1054") {
 		log.Errorf("covers: failed updating subjects, potentially incompatible database version")
 		log.Errorf("%s see https://jira.mariadb.org/browse/MDEV-25362", err)
@@ -278,6 +278,8 @@ func UpdateSubjectCovers() (err error) {
 
 // UpdateCovers updates album, subject, and label cover thumbs.
 func UpdateCovers() (err error) {
+	log.Info("index: updating covers")
+
 	// Update Albums.
 	if err = UpdateAlbumCovers(); err != nil {
 		return err

internal/query/photo.go

@@ -83,6 +83,8 @@ func PhotosMissing(limit int, offset int) (entities entity.Photos, err error) {
 
 // ResetPhotoQuality sets photo quality scores to -1 if files are missing.
 func ResetPhotoQuality() error {
+	log.Info("index: flagging hidden files")
+
 	return Db().Table("photos").
 		Where("id NOT IN (SELECT photo_id FROM files WHERE file_primary = 1 AND file_missing = 0 AND deleted_at IS NULL)").
 		Update("photo_quality", -1).Error
@@ -122,21 +124,23 @@ func OrphanPhotos() (photos entity.Photos, err error) {
 
 // FixPrimaries tries to set a primary file for photos that have none.
 func FixPrimaries() error {
+	log.Info("index: updating primary files")
+
 	var photos entity.Photos
 
 	if err := UnscopedDb().
-		Raw(`SELECT * FROM photos WHERE 
+		Raw(`SELECT * FROM photos 
-			deleted_at IS NULL 
+			WHERE deleted_at IS NULL 
 			AND id NOT IN (SELECT photo_id FROM files WHERE file_primary = 1)`).
 		Find(&photos).Error; err != nil {
 		return err
 	}
 
 	for _, p := range photos {
-		log.Debugf("photo: finding new primary for %s", p.PhotoUID)
+		log.Debugf("index: finding new primary file for photo %s", p.PhotoUID)
 
 		if err := p.SetPrimary(""); err != nil {
-			log.Infof("photo: %s", err)
+			log.Infof("index: %s (set primary)", err)
 		}
 	}
 

internal/query/purge.go

@@ -15,7 +15,7 @@ func PurgeOrphans() error {
 	} else if count > 0 {
 		log.Warnf("purge: removed %d orphan files [%s]", count, time.Since(start))
 	} else {
-		log.Infof("purge: no orphan files [%s]", time.Since(start))
+		log.Infof("purge: found no orphan files [%s]", time.Since(start))
 	}
 
 	// Remove duplicates without an original file.

internal/workers/meta.go

@@ -127,18 +127,14 @@ func (m *Meta) Start(delay time.Duration) (err error) {
 		log.Warn(err)
 	}
 
-	log.Debugf("updating photo counts")
-
 	// Update precalculated photo and file counts.
-	if err := entity.UpdatePhotoCounts(); err != nil {
+	if err := entity.UpdateCounts(); err != nil {
-		log.Warnf("metadata: %s (update counts)", err.Error())
+		log.Warnf("index: %s (update counts)", err.Error())
 	}
 
-	log.Debugf("updating cover thumbs")
-
 	// Update album, subject, and label cover thumbs.
 	if err := query.UpdateCovers(); err != nil {
-		log.Errorf("metadata: %s (update covers)", err)
+		log.Warnf("index: %s (update covers)", err)
 	}
 
 	// Run garbage collection.

internal/workers/sync_download.go

@@ -182,10 +182,10 @@ func (worker *Sync) download(a entity.Account) (complete bool, err error) {
 	// Any files downloaded?
 	if len(done) > 0 {
 		// Update precalculated photo and file counts.
-		worker.logError(entity.UpdatePhotoCounts())
+		worker.logWarn(entity.UpdateCounts())
 
 		// Update album, subject, and label cover thumbs.
-		worker.logError(query.UpdateCovers())
+		worker.logWarn(query.UpdateCovers())
 	}
 
 	return false, nil