From cd9ec023d36ae2e90f69d7970125deab83cb821f Mon Sep 17 00:00:00 2001
From: Michael Mayer <michael@photoprism.app>
Date: Fri, 22 Jul 2022 19:18:42 +0200
Subject: [PATCH] Cleanup: Remove cached JSON files and further improve logs
 #2521

Signed-off-by: Michael Mayer <michael@photoprism.app>
---
 internal/api/batch.go                  |  18 ++-
 internal/api/file_delete.go            |  21 ++-
 internal/commands/cleanup.go           |   9 +-
 internal/commands/index.go             |   7 +-
 internal/photoprism/cleanup.go         | 169 ++++++++++++++-----------
 internal/photoprism/delete.go          |  76 +++++++----
 internal/photoprism/filename.go        |   5 +
 internal/photoprism/index_mediafile.go |   2 +-
 internal/photoprism/mediafile.go       |  25 ++--
 internal/photoprism/mediafile_meta.go  |   2 +-
 internal/photoprism/mediafile_test.go  |  10 +-
 internal/query/purge.go                |   4 +-
 12 files changed, 213 insertions(+), 135 deletions(-)

diff --git a/internal/api/batch.go b/internal/api/batch.go
index 116f66292..c2ec0d76b 100644
--- a/internal/api/batch.go
+++ b/internal/api/batch.go
@@ -2,6 +2,9 @@ package api
 
 import (
 	"net/http"
+	"time"
+
+	"github.com/dustin/go-humanize/english"
 
 	"github.com/gin-gonic/gin"
 	"github.com/jinzhu/gorm"
@@ -371,7 +374,8 @@ func BatchPhotosDelete(router *gin.RouterGroup) {
 
 		log.Infof("photos: deleting %s", clean.Log(f.String()))
 
-		// Fetch selection from index.
+		// Fetch selection from index and record time.
+		deleteStart := time.Now()
 		photos, err := query.SelectedPhotos(f)
 
 		if err != nil {
@@ -381,15 +385,25 @@ func BatchPhotosDelete(router *gin.RouterGroup) {
 
 		var deleted entity.Photos
 
+		var numFiles = 0
+
 		// Delete photos.
 		for _, p := range photos {
-			if err = photoprism.DeletePhoto(p, true, true); err != nil {
+			n, err := photoprism.DeletePhoto(p, true, true)
+
+			numFiles += n
+
+			if err != nil {
 				log.Errorf("delete: %s", err)
 			} else {
 				deleted = append(deleted, p)
 			}
 		}
 
+		if numFiles > 0 {
+			log.Infof("delete: removed %s [%s]", english.Plural(numFiles, "file", "files"), time.Since(deleteStart))
+		}
+
 		// Any photos deleted?
 		if len(deleted) > 0 {
 			// Update precalculated photo and file counts.
diff --git a/internal/api/file_delete.go b/internal/api/file_delete.go
index 4b7129956..94f40a75c 100644
--- a/internal/api/file_delete.go
+++ b/internal/api/file_delete.go
@@ -15,6 +15,7 @@ import (
 	"github.com/photoprism/photoprism/internal/service"
 )
 
+// DeleteFile removes a file from storage.
 // DELETE /api/v1/photos/:uid/files/:file_uid
 //
 // Parameters:
@@ -41,42 +42,52 @@ func DeleteFile(router *gin.RouterGroup) {
 
 		file, err := query.FileByUID(fileUID)
 
+		// Found?
 		if err != nil {
-			log.Errorf("photo: %s (delete file)", err)
+			log.Errorf("files: %s (delete)", err)
 			AbortEntityNotFound(c)
 			return
 		}
 
+		// Primary file?
 		if file.FilePrimary {
-			log.Errorf("photo: cannot delete primary file")
+			log.Errorf("files: cannot delete primary file")
 			AbortDeleteFailed(c)
 			return
 		}
 
+		// Compose storage filename.
 		fileName := photoprism.FileName(file.FileRoot, file.FileName)
 		baseName := filepath.Base(fileName)
 
 		mediaFile, err := photoprism.NewMediaFile(fileName)
 
 		if err != nil {
-			log.Errorf("photo: %s (delete %s)", err, clean.Log(baseName))
+			log.Errorf("files: %s (delete %s)", err, clean.Log(baseName))
 			AbortEntityNotFound(c)
 			return
 		}
 
+		// Remove file from storage.
 		if err = mediaFile.Remove(); err != nil {
-			log.Errorf("photo: %s (delete %s from folder)", err, clean.Log(baseName))
+			log.Errorf("files: %s (delete %s from folder)", err, clean.Log(baseName))
+		} else {
+			log.Infof("files: deleted %s", clean.Log(baseName))
 		}
 
+		// Remove file from index.
 		if err = file.Delete(true); err != nil {
-			log.Errorf("photo: %s (delete %s from index)", err, clean.Log(baseName))
+			log.Errorf("files: %s (delete %s from index)", err, clean.Log(baseName))
 			AbortDeleteFailed(c)
 			return
+		} else {
+			log.Debugf("files: removed %s from index", clean.Log(baseName))
 		}
 
 		// Notify clients by publishing events.
 		PublishPhotoEvent(EntityUpdated, photoUID, c)
 
+		// Show translated success message.
 		event.SuccessMsg(i18n.MsgFileDeleted)
 
 		if p, err := query.PhotoPreloadByUID(photoUID); err != nil {
diff --git a/internal/commands/cleanup.go b/internal/commands/cleanup.go
index ccf1b3f26..1d7c60800 100644
--- a/internal/commands/cleanup.go
+++ b/internal/commands/cleanup.go
@@ -29,7 +29,7 @@ var cleanUpFlags = []cli.Flag{
 
 // cleanUpAction removes orphaned index entries, sidecar and thumbnail files.
 func cleanUpAction(ctx *cli.Context) error {
-	start := time.Now()
+	cleanupStart := time.Now()
 
 	conf := config.NewConfig(ctx)
 	service.SetConfig(conf)
@@ -53,10 +53,11 @@ func cleanUpAction(ctx *cli.Context) error {
 		Dry: ctx.Bool("dry"),
 	}
 
-	if thumbs, orphans, err := w.Start(opt); err != nil {
+	// Start cleanup worker.
+	if thumbnails, _, sidecars, err := w.Start(opt); err != nil {
 		return err
-	} else {
-		log.Infof("removed %s and %s in %s", english.Plural(orphans, "index entry", "index entries"), english.Plural(thumbs, "thumbnail", "thumbnails"), time.Since(start))
+	} else if total := thumbnails + sidecars; total > 0 {
+		log.Infof("removed %s in %s", english.Plural(total, "file", "files"), time.Since(cleanupStart))
 	}
 
 	conf.Shutdown()
diff --git a/internal/commands/index.go b/internal/commands/index.go
index 9e4466ec5..50486f303 100644
--- a/internal/commands/index.go
+++ b/internal/commands/index.go
@@ -101,10 +101,11 @@ func indexAction(ctx *cli.Context) error {
 			Dry: false,
 		}
 
-		if thumbs, orphans, err := w.Start(opt); err != nil {
+		// Start cleanup worker.
+		if thumbnails, _, sidecars, err := w.Start(opt); err != nil {
 			return err
-		} else {
-			log.Infof("cleanup: removed %s and %s [%s]", english.Plural(orphans, "index entry", "index entries"), english.Plural(thumbs, "thumbnail", "thumbnails"), time.Since(cleanupStart))
+		} else if total := thumbnails + sidecars; total > 0 {
+			log.Infof("cleanup: removed %s in total [%s]", english.Plural(total, "file", "files"), time.Since(cleanupStart))
 		}
 	}
 
diff --git a/internal/photoprism/cleanup.go b/internal/photoprism/cleanup.go
index 5b2fd80aa..b81bbac6d 100644
--- a/internal/photoprism/cleanup.go
+++ b/internal/photoprism/cleanup.go
@@ -7,6 +7,7 @@ import (
 	"path/filepath"
 	"runtime/debug"
 	"strings"
+	"time"
 
 	"github.com/dustin/go-humanize/english"
 
@@ -35,7 +36,7 @@ func NewCleanUp(conf *config.Config) *CleanUp {
 }
 
 // Start removes orphan index entries and thumbnails.
-func (w *CleanUp) Start(opt CleanUpOptions) (thumbs int, orphans int, err error) {
+func (w *CleanUp) Start(opt CleanUpOptions) (thumbs int, orphans int, sidecars int, err error) {
 	defer func() {
 		if r := recover(); r != nil {
 			err = fmt.Errorf("cleanup: %s (panic)\nstack: %s", r, debug.Stack())
@@ -45,7 +46,7 @@ func (w *CleanUp) Start(opt CleanUpOptions) (thumbs int, orphans int, err error)
 
 	if err = mutex.MainWorker.Start(); err != nil {
 		log.Warnf("cleanup: %s (start)", err)
-		return thumbs, orphans, err
+		return thumbs, orphans, sidecars, err
 	}
 
 	defer mutex.MainWorker.Stop()
@@ -54,20 +55,105 @@ func (w *CleanUp) Start(opt CleanUpOptions) (thumbs int, orphans int, err error)
 		log.Infof("cleanup: dry run, nothing will actually be removed")
 	}
 
+	// Find and remove orphan photo index entries.
+	cleanupStart := time.Now()
+	photos, err := query.OrphanPhotos()
+
+	if err != nil {
+		return thumbs, orphans, sidecars, err
+	}
+
+	var deleted []string
+
+	// Delete orphaned photos from the index and remaining sidecar files from storage, if any.
+	for _, p := range photos {
+		if mutex.MainWorker.Canceled() {
+			return thumbs, orphans, sidecars, errors.New("cleanup canceled")
+		}
+
+		if opt.Dry {
+			orphans++
+			log.Infof("cleanup: %s would be removed from index", p.String())
+			continue
+		}
+
+		// Deletes the index entry and remaining sidecar files outside the "originals" folder.
+		if n, err := DeletePhoto(p, true, false); err != nil {
+			sidecars += n
+			log.Errorf("cleanup: %s (remove orphans)", err)
+		} else {
+			orphans++
+			sidecars += n
+			deleted = append(deleted, p.PhotoUID)
+			log.Infof("cleanup: removed %s from index", p.String())
+		}
+	}
+
+	log.Infof("cleanup: removed %s and %s [%s]", english.Plural(orphans, "index entry", "index entries"), english.Plural(sidecars, "sidecar file", "sidecar files"), time.Since(cleanupStart))
+
+	// Remove orphan index entries.
+	if opt.Dry {
+		if files, err := query.OrphanFiles(); err != nil {
+			log.Errorf("index: %s (find orphan files)", err)
+		} else if l := len(files); l > 0 {
+			log.Infof("index: found %s", english.Plural(l, "orphan file", "orphan files"))
+		} else {
+			log.Infof("index: found no orphan files")
+		}
+	} else {
+		if err = query.PurgeOrphans(); err != nil {
+			log.Errorf("index: %s (purge orphans)", err)
+		}
+	}
+
+	// Remove thumbnail files.
+	thumbs, err = w.Thumbs(opt)
+
+	// Only update counts if anything was deleted.
+	if len(deleted) > 0 {
+		// Update precalculated photo and file counts.
+		if err = entity.UpdateCounts(); err != nil {
+			log.Warnf("index: %s (update counts)", err)
+		}
+
+		// Update album, subject, and label cover thumbs.
+		if err = query.UpdateCovers(); err != nil {
+			log.Warnf("index: %s (update covers)", err)
+		}
+
+		// Show success notification.
+		event.EntitiesDeleted("photos", deleted)
+	}
+
+	return thumbs, orphans, sidecars, err
+}
+
+// Thumbs removes orphan thumbnail files.
+func (w *CleanUp) Thumbs(opt CleanUpOptions) (thumbs int, err error) {
+	cleanupStart := time.Now()
+
 	var fileHashes, thumbHashes query.HashMap
 
 	// Fetch existing media and thumb file hashes.
 	if fileHashes, err = query.FileHashMap(); err != nil {
-		return thumbs, orphans, err
+		return thumbs, err
 	} else if thumbHashes, err = query.ThumbHashMap(); err != nil {
-		return thumbs, orphans, err
+		return thumbs, err
+	}
+
+	// At least one SHA1 checksum found?
+	if len(fileHashes) == 0 {
+		log.Info("cleanup: empty index, aborting search for orphaned thumbnails")
+		return thumbs, err
 	}
 
 	// Thumbnails storage path.
 	thumbPath := w.conf.ThumbCachePath()
 
+	log.Info("cleanup: searching for orphaned thumbnails")
+
 	// Find and remove orphan thumbnail files.
-	if err := fastwalk.Walk(thumbPath, func(fileName string, info os.FileMode) error {
+	err = fastwalk.Walk(thumbPath, func(fileName string, info os.FileMode) error {
 		base := filepath.Base(fileName)
 
 		if info.IsDir() || strings.HasPrefix(base, ".") {
@@ -86,7 +172,7 @@ func (w *CleanUp) Start(opt CleanUpOptions) (thumbs int, orphans int, err error)
 
 		if ok := fileHashes[hash]; ok {
 			// Do nothing.
-		} else if ok := thumbHashes[hash]; ok {
+		} else if ok = thumbHashes[hash]; ok {
 			// Do nothing.
 		} else if opt.Dry {
 			thumbs++
@@ -95,78 +181,15 @@ func (w *CleanUp) Start(opt CleanUpOptions) (thumbs int, orphans int, err error)
 			log.Warnf("cleanup: %s in %s", err, logName)
 		} else {
 			thumbs++
-			log.Debugf("cleanup: removed thumbnail %s", logName)
+			log.Debugf("cleanup: removed thumbnail %s from cache", logName)
 		}
 
 		return nil
-	}); err != nil {
-		return thumbs, orphans, err
-	}
+	})
 
-	// Find and remove orphan photo index entries.
-	photos, err := query.OrphanPhotos()
+	log.Infof("cleanup: removed %s [%s]", english.Plural(thumbs, "thumbnail file", "thumbnail files"), time.Since(cleanupStart))
 
-	if err != nil {
-		return thumbs, orphans, err
-	}
-
-	var deleted []string
-
-	purgeOriginalSidecars := conf.OriginalsDeletable()
-
-	for _, p := range photos {
-		if mutex.MainWorker.Canceled() {
-			return thumbs, orphans, errors.New("cleanup canceled")
-		}
-
-		if opt.Dry {
-			orphans++
-			log.Infof("cleanup: %s would be removed from index", p.String())
-			continue
-		}
-
-		// Delete the photo from the index without removing remaining media files.
-		if err = DeletePhoto(p, true, purgeOriginalSidecars); err != nil {
-			log.Errorf("cleanup: %s (remove orphans)", err)
-		} else {
-			orphans++
-			deleted = append(deleted, p.PhotoUID)
-			log.Debugf("cleanup: removed %s from index", p.String())
-		}
-	}
-
-	// Remove orphan index entries.
-	if opt.Dry {
-		if files, err := query.OrphanFiles(); err != nil {
-			log.Errorf("index: %s (find orphan files)", err)
-		} else if l := len(files); l > 0 {
-			log.Infof("index: found %s", english.Plural(l, "orphan file", "orphan files"))
-		} else {
-			log.Infof("index: found no orphan files")
-		}
-	} else {
-		if err = query.PurgeOrphans(); err != nil {
-			log.Errorf("index: %s (purge orphans)", err)
-		}
-	}
-
-	// Only update counts if anything was deleted.
-	if len(deleted) > 0 {
-		// Update precalculated photo and file counts.
-		if err = entity.UpdateCounts(); err != nil {
-			log.Warnf("index: %s (update counts)", err)
-		}
-
-		// Update album, subject, and label cover thumbs.
-		if err = query.UpdateCovers(); err != nil {
-			log.Warnf("index: %s (update covers)", err)
-		}
-
-		// Show success notification.
-		event.EntitiesDeleted("photos", deleted)
-	}
-
-	return thumbs, orphans, nil
+	return thumbs, err
 }
 
 // Cancel stops the current operation.
diff --git a/internal/photoprism/delete.go b/internal/photoprism/delete.go
index 2afc8c725..6019dcb6a 100644
--- a/internal/photoprism/delete.go
+++ b/internal/photoprism/delete.go
@@ -10,31 +10,35 @@ import (
 )
 
 // DeletePhoto removes a photo from the index and optionally all related media files.
-func DeletePhoto(p entity.Photo, mediaFiles bool, originals bool) error {
+func DeletePhoto(p entity.Photo, mediaFiles bool, originals bool) (numFiles int, err error) {
 	yamlFileName := p.YamlFileName(Config().OriginalsPath(), Config().SidecarPath())
 
 	// Permanently remove photo from index.
 	files, err := p.DeletePermanently()
 
 	if err != nil {
-		return err
+		return 0, err
 	}
 
 	if mediaFiles {
-		DeleteFiles(files, originals)
+		numFiles = DeleteFiles(files, originals)
 	}
 
 	// Remove sidecar backup.
-	if fs.FileExists(yamlFileName) {
-		log.Debugf("media: removing yaml sidecar %s", clean.Log(filepath.Base(yamlFileName)))
-		logWarn("media", os.Remove(yamlFileName))
+	if !fs.FileExists(yamlFileName) {
+		return numFiles, nil
+	} else if err := os.Remove(yamlFileName); err != nil {
+		log.Warnf("files: failed deleting sidecar %s", clean.Log(filepath.Base(yamlFileName)))
+	} else {
+		numFiles++
+		log.Infof("files: deleted sidecar %s", clean.Log(filepath.Base(yamlFileName)))
 	}
 
-	return nil
+	return numFiles, nil
 }
 
 // DeleteFiles permanently deletes media and related sidecar files.
-func DeleteFiles(files entity.Files, originals bool) {
+func DeleteFiles(files entity.Files, originals bool) (numFiles int) {
 	for _, file := range files {
 		fileName := FileName(file.FileRoot, file.FileName)
 
@@ -48,37 +52,53 @@ func DeleteFiles(files entity.Files, originals bool) {
 
 		// Log media file error if any.
 		if err != nil {
-			log.Debugf("media: %s not found", clean.Log(file.FileName))
+			log.Tracef("files: %s", err)
 		}
 
-		// Remove sidecar JSON files.
-		if sidecarJson := f.SidecarJsonName(); fs.FileExists(sidecarJson) {
-			log.Debugf("media: removing json sidecar %s", clean.Log(filepath.Base(sidecarJson)))
-			logWarn("delete", os.Remove(sidecarJson))
-		}
-		if exifJson, err := f.ExifToolJsonName(); err == nil && fs.FileExists(exifJson) {
-			log.Debugf("media: removing exiftool sidecar %s", clean.Log(filepath.Base(exifJson)))
-			logWarn("media", os.Remove(exifJson))
+		// Remove original JSON sidecar file, if any.
+		if jsonFile := f.FileName() + ".json"; !originals && f.Root() == entity.RootOriginals || !fs.FileExists(jsonFile) {
+			// Do nothing.
+		} else if err = os.Remove(jsonFile); err != nil {
+			log.Warnf("files: failed deleting sidecar %s", clean.Log(filepath.Base(jsonFile)))
+		} else {
+			numFiles++
+			log.Infof("files: deleted sidecar %s", clean.Log(filepath.Base(jsonFile)))
 		}
 
-		// Remove any other sidecar files.
-		logWarn("media", f.RemoveSidecars())
+		// Remove Exiftool JSON file in cache folder.
+		if exifJson, _ := ExifToolCacheName(file.FileHash); !fs.FileExists(exifJson) {
+			// Do nothing.
+		} else if err = os.Remove(exifJson); err != nil {
+			log.Warnf("files: failed deleting sidecar %s", clean.Log(filepath.Base(exifJson)))
+		} else {
+			numFiles++
+			log.Infof("files: deleted sidecar %s", clean.Log(filepath.Base(exifJson)))
+		}
+
+		// Remove any other files in the sidecar folder.
+		if n, _ := f.RemoveSidecarFiles(); n > 0 {
+			numFiles += n
+		}
 
 		// Continue if the media file does not exist or should be preserved.
 		if !fs.FileExists(fileName) {
 			continue
-		} else if !originals && f.Root() == entity.RootOriginals {
-			log.Debugf("media: skipped original %s", clean.Log(file.FileName))
-			continue
 		}
 
-		log.Debugf("media: removing %s", clean.Log(file.FileName))
-
-		// Remove media file.
-		if err = f.Remove(); err != nil {
-			log.Errorf("media: removed %s", clean.Log(file.FileName))
+		// Remove the original media file, if it exists and is allowed.
+		if relName := f.RootRelName(); relName == "" {
+			log.Warnf("files: relative filename of %s must not be empty - bug?", clean.Log(fileName))
+			continue
+		} else if !originals && f.Root() == entity.RootOriginals {
+			log.Debugf("files: skipped deleting %s", clean.Log(relName))
+			continue
+		} else if err = f.Remove(); err != nil {
+			log.Errorf("files: failed deleting %s", clean.Log(relName))
 		} else {
-			log.Infof("media: failed removing %s", clean.Log(file.FileName))
+			numFiles++
+			log.Infof("files: deleted %s", clean.Log(relName))
 		}
 	}
+
+	return numFiles
 }
diff --git a/internal/photoprism/filename.go b/internal/photoprism/filename.go
index 7fef3e3e0..b5020a49d 100644
--- a/internal/photoprism/filename.go
+++ b/internal/photoprism/filename.go
@@ -46,6 +46,11 @@ func CacheName(fileHash, namespace, cacheKey string) (cacheName string, err erro
 	return cacheName, nil
 }
 
+// ExifToolCacheName returns the ExifTool metadata cache file name.
+func ExifToolCacheName(hash string) (string, error) {
+	return CacheName(hash, "json", "exiftool.json")
+}
+
 // RelName returns the relative filename.
 func RelName(fileName, directory string) string {
 	return fs.RelName(fileName, directory)
diff --git a/internal/photoprism/index_mediafile.go b/internal/photoprism/index_mediafile.go
index 8ba5bf15f..02a0b0aab 100644
--- a/internal/photoprism/index_mediafile.go
+++ b/internal/photoprism/index_mediafile.go
@@ -107,7 +107,7 @@ func (ind *Index) MediaFile(m *MediaFile, o IndexOptions, originalName, photoUID
 			result.Status = IndexFailed
 			result.Err = fmt.Errorf("index: %s in %s (rename)", err, logName)
 			return result
-		} else if renamedSidecars, err := m.RenameSidecars(indFileName); err != nil {
+		} else if renamedSidecars, err := m.RenameSidecarFiles(indFileName); err != nil {
 			log.Errorf("index: %s in %s (rename sidecars)", err.Error(), logName)
 
 			fileRenamed = true
diff --git a/internal/photoprism/mediafile.go b/internal/photoprism/mediafile.go
index 11ea53b04..b1ab94ac9 100644
--- a/internal/photoprism/mediafile.go
+++ b/internal/photoprism/mediafile.go
@@ -1106,8 +1106,8 @@ func (m *MediaFile) Orientation() int {
 	return 1
 }
 
-// RenameSidecars moves related sidecar files.
-func (m *MediaFile) RenameSidecars(oldFileName string) (renamed map[string]string, err error) {
+// RenameSidecarFiles moves related sidecar files.
+func (m *MediaFile) RenameSidecarFiles(oldFileName string) (renamed map[string]string, err error) {
 	renamed = make(map[string]string)
 
 	sidecarPath := Config().SidecarPath()
@@ -1130,9 +1130,9 @@ func (m *MediaFile) RenameSidecars(oldFileName string) (renamed map[string]strin
 			renamed[fs.RelName(srcName, sidecarPath)] = fs.RelName(destName, sidecarPath)
 
 			if err := os.Remove(srcName); err != nil {
-				log.Errorf("media: failed removing sidecar %s", clean.Log(fs.RelName(srcName, sidecarPath)))
+				log.Errorf("files: failed removing sidecar %s", clean.Log(fs.RelName(srcName, sidecarPath)))
 			} else {
-				log.Infof("media: removed sidecar %s", clean.Log(fs.RelName(srcName, sidecarPath)))
+				log.Infof("files: removed sidecar %s", clean.Log(fs.RelName(srcName, sidecarPath)))
 			}
 
 			continue
@@ -1141,7 +1141,7 @@ func (m *MediaFile) RenameSidecars(oldFileName string) (renamed map[string]strin
 		if err := fs.Move(srcName, destName); err != nil {
 			return renamed, err
 		} else {
-			log.Infof("media: moved existing sidecar to %s", clean.Log(newName+filepath.Ext(srcName)))
+			log.Infof("files: moved existing sidecar to %s", clean.Log(newName+filepath.Ext(srcName)))
 			renamed[fs.RelName(srcName, sidecarPath)] = fs.RelName(destName, sidecarPath)
 		}
 	}
@@ -1149,12 +1149,12 @@ func (m *MediaFile) RenameSidecars(oldFileName string) (renamed map[string]strin
 	return renamed, nil
 }
 
-// RemoveSidecars permanently removes related sidecar files.
-func (m *MediaFile) RemoveSidecars() (err error) {
+// RemoveSidecarFiles permanently removes related sidecar files.
+func (m *MediaFile) RemoveSidecarFiles() (numFiles int, err error) {
 	fileName := m.FileName()
 
 	if fileName == "" {
-		return fmt.Errorf("empty filename")
+		return numFiles, fmt.Errorf("empty filename")
 	}
 
 	sidecarPath := Config().SidecarPath()
@@ -1166,18 +1166,19 @@ func (m *MediaFile) RemoveSidecars() (err error) {
 	matches, err := filepath.Glob(regexp.QuoteMeta(globPrefix) + "*")
 
 	if err != nil {
-		return err
+		return numFiles, err
 	}
 
 	for _, sidecarName := range matches {
 		if err = os.Remove(sidecarName); err != nil {
-			log.Errorf("media: failed removing sidecar %s", clean.Log(fs.RelName(sidecarName, sidecarPath)))
+			log.Errorf("files: failed deleting sidecar %s", clean.Log(fs.RelName(sidecarName, sidecarPath)))
 		} else {
-			log.Infof("media: removed sidecar %s", clean.Log(fs.RelName(sidecarName, sidecarPath)))
+			numFiles++
+			log.Infof("files: deleted sidecar %s", clean.Log(fs.RelName(sidecarName, sidecarPath)))
 		}
 	}
 
-	return nil
+	return numFiles, nil
 }
 
 // ColorProfile returns the ICC color profile name.
diff --git a/internal/photoprism/mediafile_meta.go b/internal/photoprism/mediafile_meta.go
index cbe4d0637..62a2db515 100644
--- a/internal/photoprism/mediafile_meta.go
+++ b/internal/photoprism/mediafile_meta.go
@@ -37,7 +37,7 @@ func (m *MediaFile) ExifToolJsonName() (string, error) {
 		return "", fmt.Errorf("media: exiftool json files disabled")
 	}
 
-	return CacheName(m.Hash(), "json", "exiftool.json")
+	return ExifToolCacheName(m.Hash())
 }
 
 // NeedsExifToolJson tests if an ExifTool JSON file needs to be created.
diff --git a/internal/photoprism/mediafile_test.go b/internal/photoprism/mediafile_test.go
index b715198ae..19c7ce60c 100644
--- a/internal/photoprism/mediafile_test.go
+++ b/internal/photoprism/mediafile_test.go
@@ -2325,7 +2325,7 @@ func TestMediaFile_IsPlayableVideo(t *testing.T) {
 	})
 }
 
-func TestMediaFile_RenameSidecars(t *testing.T) {
+func TestMediaFile_RenameSidecarFiles(t *testing.T) {
 	t.Run("success", func(t *testing.T) {
 		conf := config.TestConfig()
 
@@ -2354,7 +2354,7 @@ func TestMediaFile_RenameSidecars(t *testing.T) {
 			t.Fatal(err)
 		}
 
-		if renamed, err := mf.RenameSidecars(filepath.Join(conf.OriginalsPath(), "foo/bar.jpg")); err != nil {
+		if renamed, err := mf.RenameSidecarFiles(filepath.Join(conf.OriginalsPath(), "foo/bar.jpg")); err != nil {
 			t.Fatal(err)
 		} else if len(renamed) != 1 {
 			t.Errorf("len should be 2: %#v", renamed)
@@ -2375,7 +2375,7 @@ func TestMediaFile_RenameSidecars(t *testing.T) {
 	})
 }
 
-func TestMediaFile_RemoveSidecars(t *testing.T) {
+func TestMediaFile_RemoveSidecarFiles(t *testing.T) {
 	t.Run("success", func(t *testing.T) {
 		conf := config.TestConfig()
 
@@ -2399,10 +2399,12 @@ func TestMediaFile_RemoveSidecars(t *testing.T) {
 			t.Fatal(err)
 		}
 
-		if err := mf.RemoveSidecars(); err != nil {
+		if n, err := mf.RemoveSidecarFiles(); err != nil {
 			t.Fatal(err)
 		} else if fs.FileExists(sidecarName) {
 			t.Errorf("src file still exists: %s", sidecarName)
+		} else if n == 0 {
+			t.Errorf("number of files should be > 0: %s", sidecarName)
 		}
 
 		_ = os.Remove(sidecarName)
diff --git a/internal/query/purge.go b/internal/query/purge.go
index 76a5cae69..a0087a76e 100644
--- a/internal/query/purge.go
+++ b/internal/query/purge.go
@@ -14,9 +14,9 @@ func PurgeOrphans() error {
 	if count, err := PurgeOrphanFiles(); err != nil {
 		return err
 	} else if count > 0 {
-		log.Warnf("purge: removed %d orphan files from index[%s]", count, time.Since(start))
+		log.Infof("index: removed %d orphan files [%s]", count, time.Since(start))
 	} else {
-		log.Infof("purge: found no orphan files in index [%s]", time.Since(start))
+		log.Debugf("index: found no orphan files [%s]", time.Since(start))
 	}
 
 	// Remove duplicates without an original file.