People: Matching unrecognized faces has become very slow

[lastzero]

Discussed in #2022

^{Originally posted by hulmgulm February 8, 2022}
Hi,

assigning unrecognized faces got awfully slow since the last release (or the second last, I'm not sure about that). It takes now more than two minutes until I can assign the next face. From looking at the logs, it looks like there are some issues with the data:

2022-02-08 20:16:40 INFO änderungen erfolgreich gespeichert
2022-02-08 20:16:40 INFO faces: merged 77 clusters
2022-02-08 20:16:39 WARN faces: failed removing merged clusters for subject jr1e4i93ltym0svq
2022-02-08 20:16:31 WARN faces: SAF7A54HA4RCJ2UYGKND7SFCJCJEG62B has ambiguous subject jr1e4i93ltym0svq
2022-02-08 20:16:27 WARN faces: failed removing merged clusters for subject jr1e4i93ltym0svq
2022-02-08 20:16:19 WARN faces: SAF7A54HA4RCJ2UYGKND7SFCJCJEG62B has ambiguous subject jr1e4i93ltym0svq
2022-02-08 20:16:15 WARN faces: failed removing merged clusters for subject jr1e4i93ltym0svq
2022-02-08 20:16:07 WARN faces: SAF7A54HA4RCJ2UYGKND7SFCJCJEG62B has ambiguous subject jr1e4i93ltym0svq
2022-02-08 20:16:03 WARN faces: failed removing merged clusters for subject jr1e4i93ltym0svq
2022-02-08 20:15:55 WARN faces: SAF7A54HA4RCJ2UYGKND7SFCJCJEG62B has ambiguous subject jr1e4i93ltym0svq
2022-02-08 20:15:51 WARN faces: failed removing merged clusters for subject jr1e4i93ltym0svq
2022-02-08 20:15:43 WARN faces: SAF7A54HA4RCJ2UYGKND7SFCJCJEG62B has ambiguous subject jr1e4i93ltym0svq
2022-02-08 20:15:39 WARN faces: failed removing merged clusters for subject jr1e4i93ltym0svq
2022-02-08 20:15:31 WARN faces: SAF7A54HA4RCJ2UYGKND7SFCJCJEG62B has ambiguous subject jr1e4i93ltym0svq
2022-02-08 20:15:28 WARN faces: failed removing merged clusters for subject jr1e4i93ltym0svq
2022-02-08 20:15:19 WARN faces: SAF7A54HA4RCJ2UYGKND7SFCJCJEG62B has ambiguous subject jr1e4i93ltym0svq
2022-02-08 20:15:16 WARN faces: failed removing merged clusters for subject jr1e4i93ltym0svq
2022-02-08 20:15:07 WARN faces: SAF7A54HA4RCJ2UYGKND7SFCJCJEG62B has ambiguous subject jr1e4i93ltym0svq
2022-02-08 20:15:04 WARN faces: failed removing merged clusters for subject jr1e4i93ltym0svq
2022-02-08 20:14:55 WARN faces: SAF7A54HA4RCJ2UYGKND7SFCJCJEG62B has ambiguous subject jr1e4i93ltym0svq
2022-02-08 20:14:52 WARN faces: failed removing merged clusters for subject jr1e4i93ltym0svq
2022-02-08 20:14:43 WARN faces: SAF7A54HA4RCJ2UYGKND7SFCJCJEG62B has ambiguous subject jr1e4i93ltym0svq
2022-02-08 20:14:40 WARN faces: failed removing merged clusters for subject jr1e4i93ltym0svq
2022-02-08 20:14:31 WARN faces: SAF7A54HA4RCJ2UYGKND7SFCJCJEG62B has ambiguous subject jr1e4i93ltym0svq

It's always the same warning. How do I resolve this issue? Can I do something in the UI or is there something else like an SQL query I can execute (I'm familiar with that)?
I don't want to drop my data, because I spent weeks assigning all faces in my >100k photos.

Thank you!
Andreas

[cassava]

I have the same issue. Just imported 30'000 photos with ~450 new faces, and it's a real crawl to do anything. The whole page just freezes up.

Haven't check the logs yet though.

[lastzero]

Hello @cassava @hulmgulm @l8gravely :)

I am currently looking into this issue... more information would be helpful to provide you with a solution:

• Has anyone experiencing this changed config defaults, especially for the index worker interval, facial recognition parameters, or TensorFlow?
• Which PhotoPrism version(s) are affected? Did you upgrade or is this a new installation? Does it make a difference?
• Are you using the default MariaDB database version from our official docker-compose.yml config example or are you using a custom configuration / external database?
• Is it possible that you have (accidentally) assigned the same face to different people (or very similar faces that may not even belong to the same person, e.g. twins)? A sponsor recently had such a case that was difficult to resolve. Once it was resolved, the problems disappeared.

Thank you for taking the time to answer these questions, I really appreciate it. Sorry if you have already posted it somewhere!

[hulmgulm]

Hi @lastzero,

I've set the following config option
WakeupInterval: 30000
because otherwise PhotoPrism was using 100% CPU 24/7.

I started using PhotoPrism Oct 22nd and updated instantly, each time a new image was available. I think, that this issue started around beginning of February but I'm not sure about that.

At the beginning, I was using an existing MySQL instance for PhotoPrism, until I ran into upgrade issues and you dropped MySQL support. Then I migrated to MariaDB (database dump and import) and am using version 10.7.3 now. I'm using "--innodb-buffer-pool-size=1G" there.

Two weeks after I started this thread, I decided to start nearly from scratch and truncated subject, markers and faces tables and let PhotoPrism do a rescan of the images. At the beginning, it worked like a charm, but soon the issues started to come up again. It does not happen on all face assignments, but at maybe 75%. Currently, it takes about 3 minutes to get these faces saved.

I wrote a tool, which displays me all faces of a given subj_uid, face_id or subj_name. While I noticed one or two wrong assignments (which I corrected in the UI), the other faces are correct. This is a part of the most recent log:

time="2022-03-28T18:10:43Z" level=debug msg="faces: can merge MDCNKKHLDGZKYRCJZ7EDZYBBZTUXSTF4 with 5XY4C5KHJVHP2XACPRPXND57H5CCKRA5, subject jr7kdtd3u8khnpo5, dist 0.023031"
time="2022-03-28T18:10:43Z" level=debug msg="faces: can merge MDCNKKHLDGZKYRCJZ7EDZYBBZTUXSTF4 with Y55MIHW6HG4NLXPHWQHRC6VH4XA2NN4G, subject jr7kdtd3u8khnpo5, dist 0.049753"
time="2022-03-28T18:10:43Z" level=debug msg="faces: can merge MDCNKKHLDGZKYRCJZ7EDZYBBZTUXSTF4 with J4V3BXRK4QTOIEMO45N5LT7AQ6XGIQJV, subject jr7kdtd3u8khnpo5, dist 0.043881"
time="2022-03-28T18:10:43Z" level=debug msg="faces: can merge MDCNKKHLDGZKYRCJZ7EDZYBBZTUXSTF4 with JSP44VOXH6ERLYVNSXPSJRT3TM2QEJGX, subject jr7kdtd3u8khnpo5, dist 0.034311"
time="2022-03-28T18:10:43Z" level=debug msg="faces: can merge MDCNKKHLDGZKYRCJZ7EDZYBBZTUXSTF4 with QMZZVSHVZ6A3N6O4463OKO64SFOZUFG3, subject jr7kdtd3u8khnpo5, dist 0.222249"
time="2022-03-28T18:10:43Z" level=debug msg="faces: can merge MDCNKKHLDGZKYRCJZ7EDZYBBZTUXSTF4 with 26ODXCPQ44IEBSWXW5SCJSJ6QX3RDJXR, subject jr7kdtd3u8khnpo5, dist 0.119968"
time="2022-03-28T18:10:43Z" level=debug msg="faces: can merge MDCNKKHLDGZKYRCJZ7EDZYBBZTUXSTF4 with 2DLGKEZCMG7AKUZZSSP54OLZOJPYMJBB, subject jr7kdtd3u8khnpo5, dist 0.381513"
time="2022-03-28T18:10:43Z" level=debug msg="faces: can merge MDCNKKHLDGZKYRCJZ7EDZYBBZTUXSTF4 with 3SCFX57HZEWZL2GIWC7NNQC4YFV2DQVJ, subject jr7kdtd3u8khnpo5, dist 0.415974"
time="2022-03-28T18:10:43Z" level=debug msg="faces: can merge MDCNKKHLDGZKYRCJZ7EDZYBBZTUXSTF4 with 4KAYLP5QYLK3VUGTQQEEZPJAOSYVOETL, subject jr7kdtd3u8khnpo5, dist 0.423640"
time="2022-03-28T18:10:43Z" level=debug msg="faces: can merge MDCNKKHLDGZKYRCJZ7EDZYBBZTUXSTF4 with 4WG22ONA2F6T5JLM3M5IYURYFN5OU7V4, subject jr7kdtd3u8khnpo5, dist 0.405420"
time="2022-03-28T18:10:43Z" level=debug msg="faces: can merge MDCNKKHLDGZKYRCJZ7EDZYBBZTUXSTF4 with 7BITBQO4HAAKVCQR7MMI5AFN55EOYGZF, subject jr7kdtd3u8khnpo5, dist 0.371248"
time="2022-03-28T18:10:43Z" level=debug msg="faces: can merge MDCNKKHLDGZKYRCJZ7EDZYBBZTUXSTF4 with AIN476M4JWKVCBT5ZFYT3T5BGWPVNFJC, subject jr7kdtd3u8khnpo5, dist 0.397838"
time="2022-03-28T18:10:43Z" level=debug msg="faces: can merge MDCNKKHLDGZKYRCJZ7EDZYBBZTUXSTF4 with B2C3AJZM4VBS3QKIC7MJY753XFVTUXEX, subject jr7kdtd3u8khnpo5, dist 0.413219"
time="2022-03-28T18:10:43Z" level=debug msg="faces: can merge MDCNKKHLDGZKYRCJZ7EDZYBBZTUXSTF4 with BMNM6PK4TEQDPG2ZIQD4DFV26HJEF3UN, subject jr7kdtd3u8khnpo5, dist 0.374699"
time="2022-03-28T18:10:43Z" level=debug msg="faces: can merge MDCNKKHLDGZKYRCJZ7EDZYBBZTUXSTF4 with FUXZIOLD6D5D5GTTPDTQMEJUNPHJQPCL, subject jr7kdtd3u8khnpo5, dist 0.396865"
time="2022-03-28T18:10:43Z" level=debug msg="faces: can merge MDCNKKHLDGZKYRCJZ7EDZYBBZTUXSTF4 with GW76JBED4JP6B3WN2DTEBE6JER7GFJDV, subject jr7kdtd3u8khnpo5, dist 0.417725"
time="2022-03-28T18:10:43Z" level=debug msg="faces: can merge MDCNKKHLDGZKYRCJZ7EDZYBBZTUXSTF4 with H2UOEKZS6XMVEONCZYNYACOTML5W2ACI, subject jr7kdtd3u8khnpo5, dist 0.413470"
time="2022-03-28T18:10:43Z" level=debug msg="faces: can merge MDCNKKHLDGZKYRCJZ7EDZYBBZTUXSTF4 with HWELOHQ7G6HAZH6L2PURXABZT4LVEMKE, subject jr7kdtd3u8khnpo5, dist 0.398260"
time="2022-03-28T18:10:43Z" level=debug msg="faces: can merge MDCNKKHLDGZKYRCJZ7EDZYBBZTUXSTF4 with JCCDC6FBMWG2CCNXMUFOMVTBEUE4CTXZ, subject jr7kdtd3u8khnpo5, dist 0.365825"
time="2022-03-28T18:10:43Z" level=debug msg="faces: can merge MDCNKKHLDGZKYRCJZ7EDZYBBZTUXSTF4 with KZT5RICDFCJZ5GRSEGNLNELWEVXVJOHN, subject jr7kdtd3u8khnpo5, dist 0.394442"
time="2022-03-28T18:10:43Z" level=debug msg="faces: can merge MDCNKKHLDGZKYRCJZ7EDZYBBZTUXSTF4 with N77KBX7IDA26FTITNDETWFV24OL7UOTJ, subject jr7kdtd3u8khnpo5, dist 0.337689"
time="2022-03-28T18:10:43Z" level=debug msg="faces: can merge MDCNKKHLDGZKYRCJZ7EDZYBBZTUXSTF4 with OYN2NON6DHTIBULJQBASJA5XMWJSICWF, subject jr7kdtd3u8khnpo5, dist 0.399960"
time="2022-03-28T18:10:43Z" level=debug msg="faces: can merge MDCNKKHLDGZKYRCJZ7EDZYBBZTUXSTF4 with QWPJ4MA27P4DSORP4GDXTBRORGU6OCGJ, subject jr7kdtd3u8khnpo5, dist 0.373058"
time="2022-03-28T18:10:43Z" level=debug msg="faces: can merge MDCNKKHLDGZKYRCJZ7EDZYBBZTUXSTF4 with SI27JEYL6P5TA7EBWAGWALQICKKZQQ4Z, subject jr7kdtd3u8khnpo5, dist 0.381921"
time="2022-03-28T18:10:43Z" level=debug msg="faces: can merge MDCNKKHLDGZKYRCJZ7EDZYBBZTUXSTF4 with TPUAFR4BH5BNVKH4BIAWYO3SJYCK45N6, subject jr7kdtd3u8khnpo5, dist 0.417240"
time="2022-03-28T18:10:43Z" level=debug msg="faces: can merge MDCNKKHLDGZKYRCJZ7EDZYBBZTUXSTF4 with TQQV7UYABKRR6EUQ4ETRJY7YLDYLT2Y3, subject jr7kdtd3u8khnpo5, dist 0.365432"
time="2022-03-28T18:10:43Z" level=debug msg="faces: can merge MDCNKKHLDGZKYRCJZ7EDZYBBZTUXSTF4 with TXQHPIRP5TGKT3BL6UN45G7X25NOP24C, subject jr7kdtd3u8khnpo5, dist 0.336326"
time="2022-03-28T18:10:43Z" level=debug msg="faces: can merge MDCNKKHLDGZKYRCJZ7EDZYBBZTUXSTF4 with TZM66ZWBOUGUEXKYVDTH6QTIKNXBSLW3, subject jr7kdtd3u8khnpo5, dist 0.357090"
time="2022-03-28T18:10:43Z" level=debug msg="faces: can merge MDCNKKHLDGZKYRCJZ7EDZYBBZTUXSTF4 with US6DUXFHCF666YFGLT6NMFTJLDYEY7ZI, subject jr7kdtd3u8khnpo5, dist 0.356153"
time="2022-03-28T18:10:43Z" level=debug msg="faces: can merge MDCNKKHLDGZKYRCJZ7EDZYBBZTUXSTF4 with VVPTFYIBMMMS4FAJL6KB2O7TZSV524NJ, subject jr7kdtd3u8khnpo5, dist 0.414445"
time="2022-03-28T18:10:43Z" level=debug msg="faces: can merge MDCNKKHLDGZKYRCJZ7EDZYBBZTUXSTF4 with XEF52KCD4KCP5AA2ACTKX734SIFAJQD5, subject jr7kdtd3u8khnpo5, dist 0.422834"
time="2022-03-28T18:10:43Z" level=debug msg="faces: can merge MDCNKKHLDGZKYRCJZ7EDZYBBZTUXSTF4 with YTQ6DMHUWOTPEPJPIMKZIQPW6CKYMIPZ, subject jr7kdtd3u8khnpo5, dist 0.387638"
time="2022-03-28T18:10:43Z" level=warning msg="faces: JSP44VOXH6ERLYVNSXPSJRT3TM2QEJGX has ambiguous subject jr7kdtd3u8khnpo5"
time="2022-03-28T18:10:47Z" level=warning msg="faces: failed removing merged clusters for subject jr7kdtd3u8khnpo5"

I reviewed all of the mentioned faces as well as the subject and they're all of my oldest daughter.
I would love to find out, which photo is exactly causing these issues.

One thing I have to mention is, that I have many Asian friends and in the beginning it happened a lot that PhotoPrism was assigning the same person to completely different faces (e.g. middle aged male to 10 year old girl). I corrected all of these assignments.

Besides truncating the three tables mentioned above, I did only make changes to the data with PhotoPrism UI.

Maybe this helps, or maybe you can tell me what more I can do, e.g. finding the faces which prevent PhotoPrism from merging them.

Thank you!
Andreas

[l8gravely]

I wonder if part of my problem is that I'm indexing and searching for photos of my kids, from ages 0 to 19, so they all get assigned to one kid, but the faces are radically different as the kid gets older. Or not radically to my eye, but obviously quite a bit different.

It would be great is there were some better tools to dump what the DB thinks is out there, since with my 70.000+ pictures, it is slow at times, and not really obvious what's going on.

I'm using the default docker-compose.yml file, though I do pull it at points and reload it. So I'm using the default Mysql/mariadb setup (not sure which honestly) and I did try tweaking the memory size of the DB to see if that would improve things. But it's not clear where the slowdown is, if it's in the DB, or in the core code.

Can we turn on slow query logs maybe? Or could we get the logging to start putting some time stamps at the start and end of the update transaction so we can get an idea of what's going on here?

[lastzero]

We developed and tested face recognition assuming the default 15 minute background worker interval, so it is completely untested with very long intervals and not designed for that.

The worker makes sure that the faces get properly clustered/optimized in the background so that the number doesn't get too large to process. The first/next time it runs, it will cause a high server load until all faces, people, and related photos have been updated. The longer you wait, the more CPU is needed and the longer it takes.

30000s is about 8 hours if I calculated it correctly, which generally won't cause any problems (except for less frequently updated photo titles) unless you use face recognition very actively - especially by manually assigning names to many non-clustered faces or correcting wrong matches.

Even our old Core i3 server (running multiple instances and lots of other services simultaneously) rarely has a high CPU load. Maybe on the first day, when lots of faces had to be optimized and clustered, I don't remember any irregularities - but was also too busy to check the system parameters, to be honest.

From our User Manual at https://docs.photoprism.app/user-guide/organize/people/:

• Recognition does not start until your library has been fully scanned. Searching and updating faces temporarily causes a high CPU load and may take a while, depending on your hardware and the number of images you have.
• Existing clusters are automatically optimized in the background, for example, when new faces are detected, you have reported a bad match, or new files are added to your library.

Also note that while PhotoPrism can be installed on most consumer NAS devices, such hardware generally does not provide an ideal user experience for compute-intensive applications such as machine learning and face clustering:

https://docs.photoprism.app/getting-started/troubleshooting/performance/#server-cpu

[srett]

@l8gravely Did you manually tag a lot of individual faces, i.e. not just the "new faces" clusters you see under "People"? That starts to cause performance issues after a while, as it creates lots of small clusters internally.

Maybe an acceptable mitigation for now regarding this would be to skip the "optimize faces" background job if nothing changed during the last execution of that job, and nothing was edited/added by the user. I'm thinking of a really simple implementation with just an in-memory "changed" flag that isn't even persisted over restarts. It should avoid pointless CPU waste when you don't touch your instance for days.

[l8gravely]

>>>> "Simon" == Simon Rettberg ***@***.***> writes:

Simon> @l8gravely Did you manually tag a lot of individual faces, Simon> i.e. not just the "new faces" clusters you see under "People"? Simon> That starts to cause performance issues after a while, as it Simon> creates lots of small clusters internally. Not really, I've just been going through the new faces group and fixing up things where it has mis-classified people, or grouped them wrong. Simon> Maybe an acceptable mitigation for now regarding this would be Simon> to skip the "optimize faces" background job if nothing changed Simon> during the last execution of that job, and nothing was edited/ Simon> added by the user. I'm thinking of a really simple Simon> implementation with just an in-memory "changed" flag that isn't Simon> even persisted over restarts. It should avoid pointless CPU Simon> waste when you don't touch your instance for days. But the performance slowdown is when you are making changes. I don't mind if there's background optimization, though maybe it should be only during midnight to six am (for example) and only when the load on the system is under some other value. Right now my main PhotoPrisim host (the data is readonly on an NFS volume) is just sitting there pretty much idle. Now would be a good time to do optimizations. But once people do interactive work, it should stop/cancel/pause any background work to make the interactive experience better. Is there any way to get a measurement of the number and size of clusters associated with a name? And as a side note, it might be a good option to show the number of un-categorized photos for each unknown person in the new people page. That would help me target which ones need the most update work. Small groups aren't a problem, but big groups would be. Hard to know though, since I don't have a good feel for how the code is structured and more importantly, how to debug a docker application. John

[srett]

But the performance slowdown is when you are making changes. I don't mind if there's background optimization, though maybe it should be only during midnight to six am (for example) and only when the load on the system is under some other value.

Did you check if it is only slow while the background job is running? If you set the worker interval to 8 hours and wait until the CPU is idle, is assignment still slow?

Is there any way to get a measurement of the number and size of clusters associated with a name?

To see the number of faces per person:
SELECT subj_uid, subj_name, Count(*) AS facecount FROM subjects LEFT JOIN faces USING (subj_uid) GROUP BY subj_uid ORDER BY facecount DESC;

You can then query the individual faces of a subject from the faces table, which has columns like collision_radius and sample_radius. I thought it would be cool to visualize all the faces as a 2D or 3D point cloud to see if that helps identifying potentially problematic faces, but it seems a face is described through 512 floats, and after reading a paper on how to reduce higher-dimensional data for visualization I decided to give up on this idea. :)

Especially in @hulmgulm 's case, if you want to check whether specific SQL statements are responsible for the hangs you have – 3 minutes sounds excessive – try enabling slow query logging in MariaDB with a reasonable setting for slow query time (3+ seconds).

[cassava]

Hi @lastzero, thanks for taking the time to look at this!

Here's my setup:

• Image: TrueCharts.org with default configuration
• System: TrueNAS Scale / 16 threads / 32GB RAM
• Install: Fresh
• Pictures: 30000
• People: ~450
• Duplicates: 0 tagged
• Server CPU usage: ~0%
• Laptop CPU usage in browser: 100% for 1 core
• Browser: Firefox, current version

The problem was there already when I was assigning the first faces.

Loading tagged people is fast, as soon as I switch to "new", then it slows down significantly
and takes over a minute to just load the pictures. Takes even longer just to get the text cursor pointer so I can name the tagged person.

[cassava]

Ok, after playing around a little more in the People/New tab, I found the following:

• I can't really do anything while it's loading pictures
• It loads about 2-3 pics / second... much slower than with already named people, which is more or less instantaneous.
• After naming one person, it takes ~5 seconds to save the change, during which the ui is also unresponsive.

[l8gravely]

>>>> "Simon" == Simon Rettberg ***@***.***> writes:

Simon> But the performance slowdown is when you are making changes. I don't mind if there's Simon> background optimization, though maybe it should be only during midnight to six am (for Simon> example) and only when the load on the system is under some other value. Simon> Did you check if it is only slow while the background job is Simon> running? If you set the worker interval to 8 hours and wait Simon> until the CPU is idle, is assignment still slow? Nope, I haven't. What's the process for making these changes since I don't see anything in the docker-compose.yml file. Simon> Is there any way to get a measurement of the number and Simon> size of clusters associated with a name? Simon> To see the number of faces per person: Simon> SELECT subj_uid, subj_name, Count(*) AS facecount FROM subjects Simon> LEFT JOIN faces USING (subj_uid) GROUP BY subj_uid ORDER BY Simon> facecount DESC; Ok, so I need to fire up a docker shell to get access into the DBs, etc. Still working to wrap my brain around docker and debugging. New tricks, old dog. :-) Simon> You can then query the individual faces of a subject from the Simon> faces table, which has columns like collision_radius and Simon> sample_radius. I thought it would be cool to visualize all the Simon> faces as a 2D or 3D point cloud to see if that helps Simon> identifying potentially problematic faces, but it seems a face Simon> is described through 512 floats, and after reading a paper on Simon> how to reduce higher-dimensional data for visualization I Simon> decided to give up on this idea. :) I think just listing on the new faces page the number of pictures associated with each face would be a good indication of where to spend time classifying people. I've got 70,000 pictures and around 270 people tagged. Hmm... another interesting statistic would be to see how many pictures have un-tagged faces in them, vs the count of pictures with tagged, etc. Sorta like a heat-map, showing the number of faces in a photo, and also the number of unrecognized faces in that photo as well. The idea would be to allow people to find the low-hanging fruit of faces to categorized, or group photos with some found, but mostly un-categorized faces. Simon> Especially in @hulmgulm 's case, if you want to check whether Simon> specific SQL statements are responsible for the hangs you have Simon> – 3 minutes sounds excessive – try enabling slow query logging Simon> in MariaDB with a reasonable setting for slow query time (3+ Simon> seconds). More info as I get it. John