diff --git a/internal/api/album.go b/internal/api/album.go index c3bbdb851..0a8bb2e47 100644 --- a/internal/api/album.go +++ b/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)) }) } diff --git a/internal/api/api.go b/internal/api/api.go index 058236fe0..6d31d8999 100644 --- a/internal/api/api.go +++ b/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() diff --git a/internal/api/batch.go b/internal/api/batch.go index b47e63c8a..580d7cd2e 100644 --- a/internal/api/batch.go +++ b/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() diff --git a/internal/api/import.go b/internal/api/import.go index 9cd0a6190..00f4880b2 100644 --- a/internal/api/import.go +++ b/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}) diff --git a/internal/api/zip.go b/internal/api/zip.go index f1eb72713..8977801e8 100644 --- a/internal/api/zip.go +++ b/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}) }) diff --git a/internal/commands/cleanup.go b/internal/commands/cleanup.go index 07dae50c6..b61ae90e7 100644 --- a/internal/commands/cleanup.go +++ b/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 %d index entries and %d orphan thumbnails in %s", orphans, thumbs, elapsed) + log.Infof("cleanup: removed %s and %s [%s]", english.Plural(orphans, "index entry", "index entries"), english.Plural(thumbs, "thumbnail", "thumbnails"), time.Since(start)) } conf.Shutdown() diff --git a/internal/commands/faces.go b/internal/commands/faces.go index f436db1cc..ad6ee46f9 100644 --- a/internal/commands/faces.go +++ b/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() diff --git a/internal/commands/index.go b/internal/commands/index.go index cfd42b22d..f02347a36 100644 --- a/internal/commands/index.go +++ b/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() diff --git a/internal/commands/index_test.go b/internal/commands/index_test.go index f3ee311f5..13f257b2c 100644 --- a/internal/commands/index_test.go +++ b/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, "searching index for hidden media files") - assert.Contains(t, output, "updating photo counts") + assert.Contains(t, output, "index: updating primary files") + assert.Contains(t, output, "index: flagging hidden files") } else { t.Fatal("log output missing") } diff --git a/internal/commands/migrate.go b/internal/commands/migrate.go index 0a60a74af..03617a0ad 100644 --- a/internal/commands/migrate.go +++ b/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() diff --git a/internal/commands/purge.go b/internal/commands/purge.go index dd4ac7a5f..aff4c7f80 100644 --- a/internal/commands/purge.go +++ b/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() diff --git a/internal/commands/resample.go b/internal/commands/resample.go index db688cf84..91c9b126f 100644 --- a/internal/commands/resample.go +++ b/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 } diff --git a/internal/commands/reset.go b/internal/commands/reset.go index d66ae0aba..8433a2aee 100644 --- a/internal/commands/reset.go +++ b/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") } diff --git a/internal/commands/restore.go b/internal/commands/restore.go index 1c4c3e1a3..1517d9e1a 100644 --- a/internal/commands/restore.go +++ b/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() diff --git a/internal/entity/photo_counts.go b/internal/entity/counts.go similarity index 92% rename from internal/entity/photo_counts.go rename to internal/entity/counts.go index ec5fa6fff..769c3a9e6 100644 --- a/internal/entity/photo_counts.go +++ b/internal/entity/counts.go @@ -46,8 +46,8 @@ func LabelCounts() LabelPhotoCounts { return result } -// UpdatePlacesPhotoCounts updates the places photo counts. -func UpdatePlacesPhotoCounts() (err error) { +// UpdatePlacesCounts updates the places photo counts. +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. -func UpdateLabelPhotoCounts() (err error) { +// UpdateLabelCounts updates the label photo counts. +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. -func UpdatePhotoCounts() (err error) { - if err = UpdatePlacesPhotoCounts(); err != nil { +// UpdateCounts updates precalculated photo and file counts. +func UpdateCounts() (err error) { + 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 } diff --git a/internal/entity/photo_counts_test.go b/internal/entity/counts_test.go similarity index 92% rename from internal/entity/photo_counts_test.go rename to internal/entity/counts_test.go index a28f0f64d..4b9fa4819 100644 --- a/internal/entity/photo_counts_test.go +++ b/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) diff --git a/internal/entity/file.go b/internal/entity/file.go index 7b18d14f6..2d4f706e2 100644 --- a/internal/entity/file.go +++ b/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)) } } diff --git a/internal/entity/photo.go b/internal/entity/photo.go index a854c3357..6ffbd8739 100644 --- a/internal/entity/photo.go +++ b/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 { - log.Errorf("photo: %s", err) + if err := UpdateCounts(); err != nil { + 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 { - log.Errorf("photo: %s", err) + if err := UpdateCounts(); err != nil { + 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 { - log.Errorf("photo: %s", err) + if err := UpdateCounts(); err != nil { + log.Warnf("index: %s (update counts)", err) } event.Publish("count.review", event.Data{ diff --git a/internal/photoprism/cleanup.go b/internal/photoprism/cleanup.go index 238666cca..ede509490 100644 --- a/internal/photoprism/cleanup.go +++ b/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 { - log.Errorf("cleanup: %s (update counts)", err) + if err := entity.UpdateCounts(); err != nil { + 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. diff --git a/internal/photoprism/faces.go b/internal/photoprism/faces.go index 238717069..378f5b2fb 100644 --- a/internal/photoprism/faces.go +++ b/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. diff --git a/internal/photoprism/import.go b/internal/photoprism/import.go index 69c49cfa3..db31c7fa1 100644 --- a/internal/photoprism/import.go +++ b/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 { - log.Errorf("import: %s (update counts)", err) + if err := entity.UpdateCounts(); err != nil { + log.Warnf("index: %s (update counts)", err) } } diff --git a/internal/photoprism/import_worker.go b/internal/photoprism/import_worker.go index 22281ba1a..4a78bd0aa 100644 --- a/internal/photoprism/import_worker.go +++ b/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)) } } diff --git a/internal/photoprism/index.go b/internal/photoprism/index.go index bfa925679..1e61acad7 100644 --- a/internal/photoprism/index.go +++ b/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 { - log.Errorf("index: %s (update counts)", err) + if err := entity.UpdateCounts(); err != nil { + log.Warnf("index: %s (update counts)", err) } } else { log.Infof("index: no new or modified files") diff --git a/internal/photoprism/index_related.go b/internal/photoprism/index_related.go index ee206fe7a..2d4dcdde8 100644 --- a/internal/photoprism/index_related.go +++ b/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()) diff --git a/internal/photoprism/mediafile.go b/internal/photoprism/mediafile.go index f0580a466..9062d14c7 100644 --- a/internal/photoprism/mediafile.go +++ b/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)))) - case 1: - log.Info(capture.Time(start, fmt.Sprintf("media: one thumbnail created for %s", m.BasePrefix(false)))) + log.Debug(capture.Time(start, fmt.Sprintf("media: no new thumbnails 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)))) } }() diff --git a/internal/photoprism/moments.go b/internal/photoprism/moments.go index 81c5a9004..2def51e30 100644 --- a/internal/photoprism/moments.go +++ b/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 } diff --git a/internal/photoprism/purge.go b/internal/photoprism/purge.go index e75e23636..1c8bffd86 100644 --- a/internal/photoprism/purge.go +++ b/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.UpdatePhotoCounts(); err != nil { - log.Errorf("purge: %s (update counts)", err) + if err := entity.UpdateCounts(); err != nil { + log.Warnf("index: %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 diff --git a/internal/query/covers.go b/internal/query/covers.go index cac29753b..60cbe9aba 100644 --- a/internal/query/covers.go +++ b/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 diff --git a/internal/query/photo.go b/internal/query/photo.go index f0faa1c31..19388fe00 100644 --- a/internal/query/photo.go +++ b/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 - deleted_at IS NULL + Raw(`SELECT * FROM photos + 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) } } diff --git a/internal/query/purge.go b/internal/query/purge.go index 7e91dabe2..6fbadd288 100644 --- a/internal/query/purge.go +++ b/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. diff --git a/internal/workers/meta.go b/internal/workers/meta.go index 0942c66b6..8cae6bcc1 100644 --- a/internal/workers/meta.go +++ b/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 { - log.Warnf("metadata: %s (update counts)", err.Error()) + if err := entity.UpdateCounts(); err != nil { + 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. diff --git a/internal/workers/sync_download.go b/internal/workers/sync_download.go index 7be7d63f8..9f0cb7899 100644 --- a/internal/workers/sync_download.go +++ b/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