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

@@ -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")

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())
 

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

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))
 }

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.
+// onReady contains init functions to be called when the
-func MigrateDb(dropDeprecated, runFailed bool, ids []string) {
+// 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
 }

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)
 				}
 			}

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)

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 {

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))

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
+}

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)
+}

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"))
+	})
+}

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
+}

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 {
+func FindSubject(uid string) *Subject {
-	if s == "" {
+	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 uid == "" {
-	if err := UnscopedDb().Where("subj_name LIKE ?", name).First(&result).Error; err != nil {
 		return nil
 	}
 
 	// Restore if currently deleted.
-	if err := result.Restore(); err != nil {
+	if result = FindSubject(uid); result == nil {
-		log.Errorf("subject: %s could not be restored", result.SubjUID)
+		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.

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())
+	}
+}

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{

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))
 				}

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

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))
 				}

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.
+	spaces := false
-	s = strings.Trim(s, " '\"“`\t\n\r")
 
 	// 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?
+	// Contains spaces?
-	if s == "" || strings.ContainsAny(s, " ") {
+	if spaces {
 		return fmt.Sprintf("'%s'", s)
 	}
 

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://<host>:<port>/<path>}"))
 	})
+	t.Run("SpecialChars", func(t *testing.T) {
+		assert.Equal(t, "'  The ?quick? ''brown 'fox.   '", Log("  The <quick>\n\r ''brown \"fox. \t  "))
+	})
 }
 
 func TestLogLower(t *testing.T) {