From c74fcbf2822abda38980a3fc84baf787dc2bbba8 Mon Sep 17 00:00:00 2001 From: Michael Mayer Date: Mon, 4 Apr 2022 14:21:43 +0200 Subject: [PATCH] People: Show real name instead of uid in logs #1438 #2182 Since caching all subject data proved too complex in the time available, this implementation uses a simple key/value lookup table to cache subject names and perform backward searches by uid. --- internal/commands/reset.go | 2 +- internal/config/db.go | 2 +- .../entity/{counts.go => entity_counts.go} | 0 .../{counts_test.go => entity_counts_test.go} | 0 internal/entity/{db.go => entity_db.go} | 2 +- .../entity/{db_test.go => entity_db_test.go} | 0 .../{db_fixtures.go => entity_fixtures.go} | 2 +- .../entity/{db_migrate.go => entity_init.go} | 31 +++- .../entity/{db_tables.go => entity_tables.go} | 10 +- internal/entity/face.go | 6 +- internal/entity/file.go | 10 +- .../{db_mysql8_test.go => mysql8_test.go} | 0 internal/entity/{values.go => string.go} | 34 ---- internal/entity/string_keyvalue.go | 21 +++ internal/entity/string_map.go | 112 +++++++++++++ internal/entity/string_map_test.go | 153 ++++++++++++++++++ .../entity/{values_test.go => string_test.go} | 0 internal/entity/string_values.go | 38 +++++ internal/entity/subject.go | 39 +++-- internal/entity/subject_names.go | 21 +++ internal/entity/subject_person.go | 6 + internal/photoprism/faces_audit.go | 4 +- internal/photoprism/faces_optimize.go | 2 +- internal/query/faces.go | 4 +- pkg/sanitize/log.go | 17 +- pkg/sanitize/log_test.go | 3 + 26 files changed, 440 insertions(+), 79 deletions(-) rename internal/entity/{counts.go => entity_counts.go} (100%) rename internal/entity/{counts_test.go => entity_counts_test.go} (100%) rename internal/entity/{db.go => entity_db.go} (97%) rename internal/entity/{db_test.go => entity_db_test.go} (100%) rename internal/entity/{db_fixtures.go => entity_fixtures.go} (88%) rename internal/entity/{db_migrate.go => entity_init.go} (62%) rename internal/entity/{db_tables.go => entity_tables.go} (90%) rename internal/entity/{db_mysql8_test.go => mysql8_test.go} (100%) rename internal/entity/{values.go => string.go} (65%) create mode 100644 internal/entity/string_keyvalue.go create mode 100644 internal/entity/string_map.go create mode 100644 internal/entity/string_map_test.go rename internal/entity/{values_test.go => string_test.go} (100%) create mode 100644 internal/entity/string_values.go create mode 100644 internal/entity/subject_names.go diff --git a/internal/commands/reset.go b/internal/commands/reset.go index 7b508c4b0..8a749e2d7 100644 --- a/internal/commands/reset.go +++ b/internal/commands/reset.go @@ -175,7 +175,7 @@ func resetIndexDb(conf *config.Config) { tables.Drop(conf.Db()) log.Infoln("restoring default schema") - entity.MigrateDb(true, false, nil) + entity.InitDb(true, false, nil) if conf.AdminPassword() != "" { log.Infoln("restoring initial admin password") diff --git a/internal/config/db.go b/internal/config/db.go index ee4f4bbe2..676b95ad7 100644 --- a/internal/config/db.go +++ b/internal/config/db.go @@ -251,7 +251,7 @@ func (c *Config) InitDb() { func (c *Config) MigrateDb(runFailed bool, ids []string) { c.SetDbOptions() entity.SetDbProvider(c) - entity.MigrateDb(true, runFailed, ids) + entity.InitDb(true, runFailed, ids) entity.Admin.InitPassword(c.AdminPassword()) diff --git a/internal/entity/counts.go b/internal/entity/entity_counts.go similarity index 100% rename from internal/entity/counts.go rename to internal/entity/entity_counts.go diff --git a/internal/entity/counts_test.go b/internal/entity/entity_counts_test.go similarity index 100% rename from internal/entity/counts_test.go rename to internal/entity/entity_counts_test.go diff --git a/internal/entity/db.go b/internal/entity/entity_db.go similarity index 97% rename from internal/entity/db.go rename to internal/entity/entity_db.go index 4d566ed10..9a0016cb3 100644 --- a/internal/entity/db.go +++ b/internal/entity/entity_db.go @@ -67,7 +67,7 @@ func (g *Gorm) Db() *gorm.DB { g.once.Do(g.Connect) if g.db == nil { - log.Fatal("entity: database not connected") + log.Fatal("migrate: database not connected") } return g.db diff --git a/internal/entity/db_test.go b/internal/entity/entity_db_test.go similarity index 100% rename from internal/entity/db_test.go rename to internal/entity/entity_db_test.go diff --git a/internal/entity/db_fixtures.go b/internal/entity/entity_fixtures.go similarity index 88% rename from internal/entity/db_fixtures.go rename to internal/entity/entity_fixtures.go index cdafbb957..22c6d0aa0 100644 --- a/internal/entity/db_fixtures.go +++ b/internal/entity/entity_fixtures.go @@ -27,5 +27,5 @@ func ResetTestFixtures() { CreateTestFixtures() - log.Debugf("entity: recreated test fixtures [%s]", time.Since(start)) + log.Debugf("migrate: recreated test fixtures [%s]", time.Since(start)) } diff --git a/internal/entity/db_migrate.go b/internal/entity/entity_init.go similarity index 62% rename from internal/entity/db_migrate.go rename to internal/entity/entity_init.go index c1bfddf53..4894ad565 100644 --- a/internal/entity/db_migrate.go +++ b/internal/entity/entity_init.go @@ -7,8 +7,25 @@ import ( "github.com/photoprism/photoprism/pkg/sanitize" ) -// MigrateDb creates database tables and inserts default fixtures as needed. -func MigrateDb(dropDeprecated, runFailed bool, ids []string) { +// onReady contains init functions to be called when the +// initialization of the database is complete. +var onReady []func() + +// ready executes init callbacks when the initialization of the +// database is complete. +func ready() { + for _, init := range onReady { + init() + } +} + +// InitDb creates database tables and inserts default fixtures as needed. +func InitDb(dropDeprecated, runFailed bool, ids []string) { + if !HasDbProvider() { + log.Error("migrate: no database provider") + return + } + start := time.Now() if dropDeprecated && len(ids) == 0 { @@ -20,7 +37,9 @@ func MigrateDb(dropDeprecated, runFailed bool, ids []string) { CreateDefaultFixtures() - log.Debugf("entity: successfully initialized [%s]", time.Since(start)) + ready() + + log.Debugf("migrate: completed in %s", time.Since(start)) } // InitTestDb connects to and completely initializes the test database incl fixtures. @@ -29,6 +48,8 @@ func InitTestDb(driver, dsn string) *Gorm { return nil } + start := time.Now() + // Set default test database driver. if driver == "test" || driver == "sqlite" || driver == "" || dsn == "" { driver = SQLite3 @@ -58,5 +79,9 @@ func InitTestDb(driver, dsn string) *Gorm { ResetTestFixtures() File{}.RegenerateIndex() + ready() + + log.Debugf("migrate: completed in %s", time.Since(start)) + return db } diff --git a/internal/entity/db_tables.go b/internal/entity/entity_tables.go similarity index 90% rename from internal/entity/db_tables.go rename to internal/entity/entity_tables.go index 0fd6a4307..318b29528 100644 --- a/internal/entity/db_tables.go +++ b/internal/entity/entity_tables.go @@ -56,10 +56,10 @@ func (list Tables) WaitForMigration(db *gorm.DB) { for i := 0; i <= attempts; i++ { count := RowCount{} if err := db.Raw(fmt.Sprintf("SELECT COUNT(*) AS count FROM %s", name)).Scan(&count).Error; err == nil { - log.Tracef("entity: %s migrated", sanitize.Log(name)) + log.Tracef("migrate: %s migrated", sanitize.Log(name)) break } else { - log.Debugf("entity: waiting for %s migration (%s)", sanitize.Log(name), err.Error()) + log.Debugf("migrate: waiting for %s migration (%s)", sanitize.Log(name), err.Error()) } if i == attempts { @@ -78,7 +78,7 @@ func (list Tables) Truncate(db *gorm.DB) { // log.Debugf("entity: removed all data from %s", name) break } else if err.Error() != "record not found" { - log.Debugf("entity: %s in %s", err, sanitize.Log(name)) + log.Debugf("migrate: %s in %s", err, sanitize.Log(name)) } } } @@ -88,12 +88,12 @@ func (list Tables) Migrate(db *gorm.DB, runFailed bool, ids []string) { if len(ids) == 0 { for name, entity := range list { if err := db.AutoMigrate(entity).Error; err != nil { - log.Debugf("entity: %s (waiting 1s)", err.Error()) + log.Debugf("migrate: %s (waiting 1s)", err.Error()) time.Sleep(time.Second) if err := db.AutoMigrate(entity).Error; err != nil { - log.Errorf("entity: failed migrating %s", sanitize.Log(name)) + log.Errorf("migrate: failed migrating %s", sanitize.Log(name)) panic(err) } } diff --git a/internal/entity/face.go b/internal/entity/face.go index 62c428df5..672db6179 100644 --- a/internal/entity/face.go +++ b/internal/entity/face.go @@ -166,7 +166,7 @@ func (m *Face) ResolveCollision(embeddings face.Embeddings) (resolved bool, err return false, fmt.Errorf("collision distance must be positive") } else if dist < 0.02 { // Ignore if distance is very small as faces may belong to the same person. - log.Warnf("face %s: clearing ambiguous subject %s, similar face at dist %f with source %s", m.ID, m.SubjUID, dist, SrcString(m.FaceSrc)) + log.Warnf("face %s: clearing ambiguous subject %s, similar face at dist %f with source %s", m.ID, SubjNames.Log(m.SubjUID), dist, SrcString(m.FaceSrc)) // Reset subject UID just in case. m.SubjUID = "" @@ -341,12 +341,12 @@ func FirstOrCreateFace(m *Face) *Face { result := Face{} if err := UnscopedDb().Where("id = ?", m.ID).First(&result).Error; err == nil { - log.Warnf("faces: %s has ambiguous subject %s", m.ID, m.SubjUID) + log.Warnf("faces: %s has ambiguous subject %s", m.ID, SubjNames.Log(m.SubjUID)) return &result } else if createErr := m.Create(); createErr == nil { return m } else if err := UnscopedDb().Where("id = ?", m.ID).First(&result).Error; err == nil { - log.Warnf("faces: %s has ambiguous subject %s", m.ID, m.SubjUID) + log.Warnf("faces: %s has ambiguous subject %s", m.ID, SubjNames.Log(m.SubjUID)) return &result } else { log.Errorf("faces: %s when trying to create %s", createErr, m.ID) diff --git a/internal/entity/file.go b/internal/entity/file.go index 27c6b9c46..ee24be9ed 100644 --- a/internal/entity/file.go +++ b/internal/entity/file.go @@ -105,16 +105,16 @@ func (m File) RegenerateIndex() { if m.PhotoID > 0 { updateWhere = gorm.Expr("photo_id = ?", m.PhotoID) - scope = "partial" + scope = "partial file index" } else if m.PhotoUID != "" { updateWhere = gorm.Expr("photo_uid = ?", m.PhotoUID) - scope = "partial" + scope = "partial file index" } else if m.ID > 0 { updateWhere = gorm.Expr("id = ?", m.ID) - scope = "file" + scope = "partial file index" } else { updateWhere = gorm.Expr("photo_id IS NOT NULL") - scope = "full" + scope = "file index" } switch DbDialect() { @@ -146,7 +146,7 @@ func (m File) RegenerateIndex() { log.Warnf("sql: unsupported dialect %s", DbDialect()) } - log.Debugf("files: updated %s search index [%s]", scope, time.Since(start)) + log.Debugf("search: updated %s [%s]", scope, time.Since(start)) } type FileInfos struct { diff --git a/internal/entity/db_mysql8_test.go b/internal/entity/mysql8_test.go similarity index 100% rename from internal/entity/db_mysql8_test.go rename to internal/entity/mysql8_test.go diff --git a/internal/entity/values.go b/internal/entity/string.go similarity index 65% rename from internal/entity/values.go rename to internal/entity/string.go index 5dfd53ab8..95e52899d 100644 --- a/internal/entity/values.go +++ b/internal/entity/string.go @@ -1,7 +1,6 @@ package entity import ( - "reflect" "strings" ) @@ -9,39 +8,6 @@ const ( ClipStringType = 64 ) -// Values is a shortcut for map[string]interface{} -type Values map[string]interface{} - -// GetValues extracts entity Values. -func GetValues(m interface{}, omit ...string) (result Values) { - skip := func(name string) bool { - for _, s := range omit { - if name == s { - return true - } - } - - return false - } - - result = make(map[string]interface{}) - - elem := reflect.ValueOf(m).Elem() - relType := elem.Type() - - for i := 0; i < relType.NumField(); i++ { - name := relType.Field(i).Name - - if skip(name) { - continue - } - - result[name] = elem.Field(i).Interface() - } - - return result -} - // ToASCII removes all non-ascii characters from a string and returns it. func ToASCII(s string) string { result := make([]rune, 0, len(s)) diff --git a/internal/entity/string_keyvalue.go b/internal/entity/string_keyvalue.go new file mode 100644 index 000000000..90b90f1cd --- /dev/null +++ b/internal/entity/string_keyvalue.go @@ -0,0 +1,21 @@ +package entity + +// KeyValue represents a string key/value pair. +type KeyValue struct { + K string `json:"value"` + V string `json:"text"` +} + +// KeyValues represents a list of string key/value pairs. +type KeyValues []KeyValue + +// Strings returns the list as a lookup map. +func (v KeyValues) Strings() Strings { + result := make(Strings, len(v)) + + for i := range v { + result[v[i].K] = v[i].V + } + + return result +} diff --git a/internal/entity/string_map.go b/internal/entity/string_map.go new file mode 100644 index 000000000..d9a18a82b --- /dev/null +++ b/internal/entity/string_map.go @@ -0,0 +1,112 @@ +package entity + +import ( + "strings" + "sync" + + "github.com/photoprism/photoprism/pkg/sanitize" +) + +// Strings is a simple string map that should not be accessed by multiple goroutines. +type Strings map[string]string + +// StringMap is a string (reverse) lookup map that can be accessed by multiple goroutines. +type StringMap struct { + sync.RWMutex + m Strings + r Strings +} + +// NewStringMap creates a new string (reverse) lookup map. +func NewStringMap(s Strings) *StringMap { + if s == nil { + return &StringMap{m: make(Strings, 64), r: make(Strings, 64)} + } else { + m := &StringMap{m: s, r: make(Strings, len(s))} + + for k := range s { + m.r[strings.ToLower(s[k])] = k + } + + return m + } +} + +// Get returns a string from the map, empty if not found. +func (s *StringMap) Get(key string) string { + if key == "" { + return "" + } + + s.RLock() + defer s.RUnlock() + + return s.m[key] +} + +// Key returns a string from the map, empty if not found. +func (s *StringMap) Key(val string) string { + if val == "" { + return "" + } + + s.RLock() + defer s.RUnlock() + + return s.r[strings.ToLower(val)] +} + +// Log returns a string sanitized for logging and using the key as fallback value. +func (s *StringMap) Log(key string) (val string) { + if val = s.Get(key); val != "" { + return sanitize.Log(val) + } else { + return sanitize.Log(key) + } +} + +// Unchanged verifies if the key/value pair is unchanged. +func (s *StringMap) Unchanged(key string, val string) bool { + if key == "" { + return true + } + + s.RLock() + defer s.RUnlock() + + return s.m[key] == val && s.r[strings.ToLower(val)] == key +} + +// Set adds a string to the map. +func (s *StringMap) Set(key string, val string) { + if s.Unchanged(key, val) { + return + } else if val == "" { + s.Unset(key) + return + } + + s.Lock() + defer s.Unlock() + + s.m[key] = val + s.r[strings.ToLower(val)] = key +} + +// Unset removes a string from the map. +func (s *StringMap) Unset(key string) { + if key == "" { + return + } + + s.Lock() + defer s.Unlock() + + if v := s.m[key]; v == "" { + // Should never happen. + } else if v = strings.ToLower(v); s.r[v] == key { + delete(s.r, v) + } + + delete(s.m, key) +} diff --git a/internal/entity/string_map_test.go b/internal/entity/string_map_test.go new file mode 100644 index 000000000..cea13820f --- /dev/null +++ b/internal/entity/string_map_test.go @@ -0,0 +1,153 @@ +package entity + +import ( + "testing" + + "github.com/stretchr/testify/assert" +) + +func TestNewStringMap(t *testing.T) { + t.Run("Nil", func(t *testing.T) { + m := NewStringMap(nil) + + assert.Equal(t, "", m.Get("foo")) + }) + t.Run("Strings", func(t *testing.T) { + m := NewStringMap(Strings{"foo": "bar", "bar": "baz"}) + + assert.Equal(t, "bar", m.Get("foo")) + assert.Equal(t, "", m.Get("FOO")) + assert.Equal(t, "baz", m.Get("bar")) + assert.Equal(t, "", m.Get("bAr")) + assert.Equal(t, "", m.Get("baz")) + assert.Equal(t, "", m.Get("")) + }) +} + +func TestStringMap_Set(t *testing.T) { + t.Run("StartingEmpty", func(t *testing.T) { + m := NewStringMap(nil) + + assert.Equal(t, "", m.Get("foo")) + + m.Set("foo", "bar") + + assert.Equal(t, "bar", m.Get("foo")) + + m.Set("foo", "bar") + + assert.Equal(t, "bar", m.Get("foo")) + + m.Set("foo", "xxx") + + assert.Equal(t, "xxx", m.Get("foo")) + + m.Set("foo", "") + + assert.Equal(t, "", m.Get("foo")) + }) + t.Run("WithStrings", func(t *testing.T) { + m := NewStringMap(Strings{"foo": "bar", "bar": "baz"}) + + assert.Equal(t, "bar", m.Get("foo")) + + m.Set("foo", "bar") + + assert.Equal(t, "baz", m.Get("bar")) + + m.Set("bar", "") + + assert.Equal(t, "", m.Get("bar")) + + m.Set("foo", "xxx") + + assert.Equal(t, "xxx", m.Get("foo")) + + m.Set("foo", "") + + assert.Equal(t, "", m.Get("foo")) + }) +} + +func TestStringMap_Key(t *testing.T) { + t.Run("StartingEmpty", func(t *testing.T) { + m := NewStringMap(nil) + + assert.Equal(t, "", m.Get("foo")) + + m.Set("foo", "bar") + m.Set("cat", "Windows") + m.Set("dog", "WINDOWS") + m.Set("Dog", "WINDOWS") + + assert.Equal(t, "Dog", m.Key("windows")) + assert.Equal(t, "Dog", m.Key("Windows")) + assert.Equal(t, "Dog", m.Key("WINDOWS")) + assert.Equal(t, "bar", m.Get("foo")) + + m.Unset("Dog") + + assert.Equal(t, "", m.Key("WINDOWS")) + assert.Equal(t, "foo", m.Key("bar")) + assert.Equal(t, "", m.Key("Dog")) + }) + t.Run("WithStrings", func(t *testing.T) { + m := NewStringMap(Strings{"foo": "bar", "bar": "baz", "Bar": "Windows"}) + + assert.Equal(t, "Bar", m.Key("windows")) + assert.Equal(t, "Bar", m.Key("Windows")) + assert.Equal(t, "bar", m.Get("foo")) + + m.Set("Foo", "Bar") + m.Set("My", "Bar") + + assert.Equal(t, "bar", m.Get("foo")) + assert.Equal(t, "Bar", m.Get("Foo")) + assert.Equal(t, "Bar", m.Get("My")) + assert.Equal(t, "My", m.Key("bar")) + + m.Set("My", "") + + assert.Equal(t, "", m.Get("My")) + assert.Equal(t, "", m.Key("bar")) + }) +} + +func TestStringMap_Unset(t *testing.T) { + t.Run("StartingEmpty", func(t *testing.T) { + m := NewStringMap(nil) + + assert.Equal(t, "", m.Get("foo")) + + m.Unset("foo") + + assert.Equal(t, "", m.Get("foo")) + + m.Set("foo", "xxx") + + assert.Equal(t, "xxx", m.Get("foo")) + + m.Unset("foo") + + assert.Equal(t, "", m.Get("foo")) + assert.Equal(t, "", m.Get("bar")) + }) + t.Run("WithStrings", func(t *testing.T) { + m := NewStringMap(Strings{"foo": "bar", "bar": "baz"}) + + assert.Equal(t, "bar", m.Get("foo")) + + m.Unset("foo") + + assert.Equal(t, "", m.Get("foo")) + + m.Set("foo", "xxx") + + assert.Equal(t, "xxx", m.Get("foo")) + + m.Unset("foo") + + assert.Equal(t, "", m.Get("foo")) + assert.Equal(t, "baz", m.Get("bar")) + }) +} diff --git a/internal/entity/values_test.go b/internal/entity/string_test.go similarity index 100% rename from internal/entity/values_test.go rename to internal/entity/string_test.go diff --git a/internal/entity/string_values.go b/internal/entity/string_values.go new file mode 100644 index 000000000..2d5add301 --- /dev/null +++ b/internal/entity/string_values.go @@ -0,0 +1,38 @@ +package entity + +import ( + "reflect" +) + +// Values is a shortcut for map[string]interface{} +type Values map[string]interface{} + +// GetValues extracts entity Values. +func GetValues(m interface{}, omit ...string) (result Values) { + skip := func(name string) bool { + for _, s := range omit { + if name == s { + return true + } + } + + return false + } + + result = make(map[string]interface{}) + + elem := reflect.ValueOf(m).Elem() + relType := elem.Type() + + for i := 0; i < relType.NumField(); i++ { + name := relType.Field(i).Name + + if skip(name) { + continue + } + + result[name] = elem.Field(i).Interface() + } + + return result +} diff --git a/internal/entity/subject.go b/internal/entity/subject.go index 5c5e14de2..34c3d1eda 100644 --- a/internal/entity/subject.go +++ b/internal/entity/subject.go @@ -57,6 +57,18 @@ func (m *Subject) BeforeCreate(scope *gorm.Scope) error { return scope.SetColumn("SubjUID", rnd.PPID('j')) } +// AfterSave is a hook that updates the name cache after saving. +func (m *Subject) AfterSave() (err error) { + SubjNames.Set(m.SubjUID, m.SubjName) + return +} + +// AfterFind is a hook that updates the name cache after querying. +func (m *Subject) AfterFind() (err error) { + SubjNames.Set(m.SubjUID, m.SubjName) + return +} + // NewSubject returns a new entity. func NewSubject(name, subjType, subjSrc string) *Subject { // Name is required. @@ -180,7 +192,7 @@ func FirstOrCreateSubject(m *Subject) *Subject { if found := FindSubjectByName(m.SubjName); found != nil { return found - } else if createErr := m.Create(); createErr == nil { + } else if err := m.Create(); err == nil { log.Infof("subject: added %s %s", TypeString(m.SubjType), sanitize.Log(m.SubjName)) event.EntitiesCreated("subjects", []*Subject{m}) @@ -196,21 +208,21 @@ func FirstOrCreateSubject(m *Subject) *Subject { } else if found = FindSubjectByName(m.SubjName); found != nil { return found } else { - log.Errorf("subject: %s while creating %s", createErr, sanitize.Log(m.SubjName)) + log.Errorf("subject: %s while creating %s", err, sanitize.Log(m.SubjName)) } return nil } // FindSubject returns an existing entity if exists. -func FindSubject(s string) *Subject { - if s == "" { +func FindSubject(uid string) *Subject { + if uid == "" { return nil } result := Subject{} - if err := UnscopedDb().Where("subj_uid = ?", s).First(&result).Error; err != nil { + if err := UnscopedDb().Where("subj_uid = ?", uid).First(&result).Error; err != nil { return nil } @@ -218,28 +230,29 @@ func FindSubject(s string) *Subject { } // FindSubjectByName find an existing subject by name. -func FindSubjectByName(name string) *Subject { +func FindSubjectByName(name string) (result *Subject) { name = sanitize.Name(name) if name == "" { return nil } - result := Subject{} + uid := SubjNames.Key(name) - // Search database. - if err := UnscopedDb().Where("subj_name LIKE ?", name).First(&result).Error; err != nil { + if uid == "" { return nil } // Restore if currently deleted. - if err := result.Restore(); err != nil { - log.Errorf("subject: %s could not be restored", result.SubjUID) + if result = FindSubject(uid); result == nil { + return nil + } else if err := result.Restore(); err != nil { + log.Errorf("subject: %s could not be restored", sanitize.Log(result.SubjName)) } else { - log.Debugf("subject: %s restored", result.SubjUID) + log.Debugf("subject: %s restored", sanitize.Log(result.SubjName)) } - return &result + return result } // IsPerson tests if the subject is a person. diff --git a/internal/entity/subject_names.go b/internal/entity/subject_names.go new file mode 100644 index 000000000..ddec8931a --- /dev/null +++ b/internal/entity/subject_names.go @@ -0,0 +1,21 @@ +package entity + +// SubjNames is a uid/name (reverse) lookup map +var SubjNames = NewStringMap(nil) + +func init() { + onReady = append(onReady, initSubjNames) +} + +// initSubjNames initializes the subject uid/name (reverse) lookup table. +func initSubjNames() { + var results KeyValues + + // Fetch subjects from the database. + if err := UnscopedDb().Model(Subject{}).Select("subj_uid AS k, subj_name AS v"). + Scan(&results).Error; err != nil { + log.Warnf("subjects: %s (init lookup)", err) + } else { + SubjNames = NewStringMap(results.Strings()) + } +} diff --git a/internal/entity/subject_person.go b/internal/entity/subject_person.go index 9c7a4fb98..8ca3d1159 100644 --- a/internal/entity/subject_person.go +++ b/internal/entity/subject_person.go @@ -22,6 +22,12 @@ type Person struct { SubjHidden bool `json:"Hidden"` } +// AfterFind is a hook that updates the name cache after querying. +func (m *Person) AfterFind() (err error) { + SubjNames.Set(m.SubjUID, m.SubjName) + return +} + // NewPerson returns a new entity. func NewPerson(subj Subject) *Person { result := &Person{ diff --git a/internal/photoprism/faces_audit.go b/internal/photoprism/faces_audit.go index 6038f663e..65fb0ae0e 100644 --- a/internal/photoprism/faces_audit.go +++ b/internal/photoprism/faces_audit.go @@ -78,13 +78,13 @@ func (w *Faces) Audit(fix bool) (err error) { log.Infof("face %s: ambiguous subject at dist %f, Ø %f from %d samples, collision Ø %f", f1.ID, dist, r, f1.Samples, f1.CollisionRadius) if f1.SubjUID != "" { - log.Infof("face %s: subject %s (%s %s)", f1.ID, sanitize.Log(subj[f1.SubjUID].SubjName), f1.SubjUID, entity.SrcString(f1.FaceSrc)) + log.Infof("face %s: subject %s (%s %s)", f1.ID, entity.SubjNames.Log(f1.SubjUID), f1.SubjUID, entity.SrcString(f1.FaceSrc)) } else { log.Infof("face %s: has no subject (%s)", f1.ID, entity.SrcString(f1.FaceSrc)) } if f2.SubjUID != "" { - log.Infof("face %s: subject %s (%s %s)", f2.ID, sanitize.Log(subj[f2.SubjUID].SubjName), f2.SubjUID, entity.SrcString(f2.FaceSrc)) + log.Infof("face %s: subject %s (%s %s)", f2.ID, entity.SubjNames.Log(f2.SubjUID), f2.SubjUID, entity.SrcString(f2.FaceSrc)) } else { log.Infof("face %s: has no subject (%s)", f2.ID, entity.SrcString(f2.FaceSrc)) } diff --git a/internal/photoprism/faces_optimize.go b/internal/photoprism/faces_optimize.go index d146d34a2..470c48829 100644 --- a/internal/photoprism/faces_optimize.go +++ b/internal/photoprism/faces_optimize.go @@ -49,7 +49,7 @@ func (w *Faces) Optimize() (result FacesOptimizeResult, err error) { merge = nil } else if ok, dist := merge[0].Match(face.Embeddings{faces[j].Embedding()}); ok { - log.Debugf("faces: can merge %s with %s, subject %s, dist %f", merge[0].ID, faces[j].ID, merge[0].SubjUID, dist) + log.Debugf("faces: can merge %s with %s, subject %s, dist %f", merge[0].ID, faces[j].ID, entity.SubjNames.Log(merge[0].SubjUID), dist) merge = append(merge, faces[j]) } else if len(merge) == 1 { merge = nil diff --git a/internal/query/faces.go b/internal/query/faces.go index 01d2c322b..bd6d1823c 100644 --- a/internal/query/faces.go +++ b/internal/query/faces.go @@ -185,13 +185,13 @@ func ResolveFaceCollisions() (conflicts, resolved int, err error) { log.Infof("face %s: ambiguous subject at dist %f, Ø %f from %d samples, collision Ø %f", f1.ID, dist, r, f1.Samples, f1.CollisionRadius) if f1.SubjUID != "" { - log.Debugf("face %s: subject %s (%s %s)", f1.ID, sanitize.Log(f1.SubjUID), f1.SubjUID, entity.SrcString(f1.FaceSrc)) + log.Debugf("face %s: subject %s (%s %s)", f1.ID, entity.SubjNames.Log(f1.SubjUID), f1.SubjUID, entity.SrcString(f1.FaceSrc)) } else { log.Debugf("face %s: has no subject (%s)", f1.ID, entity.SrcString(f1.FaceSrc)) } if f2.SubjUID != "" { - log.Debugf("face %s: subject %s (%s %s)", f2.ID, sanitize.Log(f2.SubjUID), f2.SubjUID, entity.SrcString(f2.FaceSrc)) + log.Debugf("face %s: subject %s (%s %s)", f2.ID, entity.SubjNames.Log(f2.SubjUID), f2.SubjUID, entity.SrcString(f2.FaceSrc)) } else { log.Debugf("face %s: has no subject (%s)", f2.ID, entity.SrcString(f2.FaceSrc)) } diff --git a/pkg/sanitize/log.go b/pkg/sanitize/log.go index 225b0cfb9..247b9b931 100644 --- a/pkg/sanitize/log.go +++ b/pkg/sanitize/log.go @@ -3,25 +3,28 @@ package sanitize import ( "fmt" "strings" - "unicode" ) // Log sanitizes strings created from user input in response to the log4j debacle. func Log(s string) string { - if reject(s, 512) { + if s == "" { + return "''" + } else if reject(s, 512) { return "?" } - // Trim quotes, tabs, and newline characters. - s = strings.Trim(s, " '\"“`\t\n\r") + spaces := false // Remove non-printable and other potentially problematic characters. s = strings.Map(func(r rune) rune { - if !unicode.IsPrint(r) { + if r < 32 { return -1 } switch r { + case ' ': + spaces = true + return r case '`', '"': return '\'' case '\\', '$', '<', '>', '{', '}': @@ -31,8 +34,8 @@ func Log(s string) string { } }, s) - // Empty? - if s == "" || strings.ContainsAny(s, " ") { + // Contains spaces? + if spaces { return fmt.Sprintf("'%s'", s) } diff --git a/pkg/sanitize/log_test.go b/pkg/sanitize/log_test.go index 57425104d..91f38fe72 100644 --- a/pkg/sanitize/log_test.go +++ b/pkg/sanitize/log_test.go @@ -22,6 +22,9 @@ func TestLog(t *testing.T) { t.Run("Ldap", func(t *testing.T) { assert.Equal(t, "?", Log("User-Agent: {jndi:ldap://:/}")) }) + t.Run("SpecialChars", func(t *testing.T) { + assert.Equal(t, "' The ?quick? ''brown 'fox. '", Log(" The \n\r ''brown \"fox. \t ")) + }) } func TestLogLower(t *testing.T) {