Darktable 3.0 is eating my CPU

anarcat · January 5, 2020, 9:40pm

Something happened since I upgraded from Darktable 2.6.0. Even when doing nothing at all, Darktable is taking up a whole CPU all to itself, and it’s upsetting my poor CPU fan, which is spinning like crazy. top(1) sees this:

  PID USER      PR  NI    VIRT    RES    SHR S  %CPU  %MEM     TIME+ COMMAND                                                                                                                  
 6210 anarcat   20   0 1985544 180476  62832 R  81,7   1,1   0:31.02 darktable

That’s 80% of the CPU eaten while it’s just sitting there. It comes and goes, sometimes it drops down to nothing, but then jumps back up randomly, without apparent reason. While writing this, the CPU usage dropped down to zero and backup a few times, for example.

I can’t quite figure out what’s causing this, but it’s new: DT used to be quite nice to my CPU. Sure, it would take some cycles to render images and slow down a bit when I would fire up some funky modules, but never like this, just sitting there.

Is there any way to figure out what’s going on?

I started DT with -d all, but there’s just way too much stuff output to figure out anything… There’s actually so much output that it fills up my terminal backscroll regularly. I had to stop the output to see stuff like this, which seems to fire up every 20 seconds or so:

80,199821 [sql] /build/darktable-w3LGls/darktable-3.0.0/src/libs/metadata.c:144, function update(): prepare "SELECT key, value, COUNT(id) AS ct FROM main.meta_data WHERE id = ?1 GROUP BY key, value ORDER BY value"
80,200316 [sql] /build/darktable-w3LGls/darktable-3.0.0/src/common/image.c:181, function dt_image_film_roll(): prepare "SELECT folder FROM main.film_rolls WHERE id = ?1"
80,200617 [sql] /build/darktable-w3LGls/darktable-3.0.0/src/common/image.c:226, function dt_image_full_path(): prepare "SELECT folder || '/' || filename FROM main.images i, main.film_rolls f WHERE i.film_id = f.id and i.id = ?1"
80,201160 [sql] /build/darktable-w3LGls/darktable-3.0.0/src/common/metadata.c:305, function dt_metadata_get_xmp(): prepare "SELECT value FROM main.meta_data WHERE id = ?1 AND key = ?2 ORDER BY value"
80,201219 [sql] /build/darktable-w3LGls/darktable-3.0.0/src/common/metadata.c:305, function dt_metadata_get_xmp(): prepare "SELECT value FROM main.meta_data WHERE id = ?1 AND key = ?2 ORDER BY value"
80,201264 [sql] /build/darktable-w3LGls/darktable-3.0.0/src/common/metadata.c:305, function dt_metadata_get_xmp(): prepare "SELECT value FROM main.meta_data WHERE id = ?1 AND key = ?2 ORDER BY value"
80,201315 [sql] /build/darktable-w3LGls/darktable-3.0.0/src/common/tags.c:604, function dt_set_darktable_tags(): prepare "SELECT COUNT(*) FROM memory.darktable_tags"
80,201339 [sql] /build/darktable-w3LGls/darktable-3.0.0/src/common/tags.c:634, function dt_tag_get_attached(): prepare "SELECT DISTINCT T.id, T.name, T.flags, T.synonyms, 1 AS inb FROM main.tagged_images AS I JOIN data.tags T on T.id = I.tagid WHERE I.imgid = 39025 AND T.id NOT IN memory.darktable_tags ORDER BY T.name"
80,201409 [sql] /build/darktable-w3LGls/darktable-3.0.0/src/common/tags.c:1176, function dt_selected_images_count(): prepare "SELECT count(*) FROM main.selected_images"
80,201641 [sql] /build/darktable-w3LGls/darktable-3.0.0/src/common/tags.c:604, function dt_set_darktable_tags(): prepare "SELECT COUNT(*) FROM memory.darktable_tags"
80,201663 [sql] /build/darktable-w3LGls/darktable-3.0.0/src/common/tags.c:634, function dt_tag_get_attached(): prepare "SELECT DISTINCT T.id, T.name, T.flags, T.synonyms, 1 AS inb FROM main.tagged_images AS I JOIN data.tags T on T.id = I.tagid WHERE I.imgid = 39025 AND T.id NOT IN memory.darktable_tags ORDER BY T.name"
80,201728 [sql] /build/darktable-w3LGls/darktable-3.0.0/src/common/tags.c:1176, function dt_selected_images_count(): prepare "SELECT count(*) FROM main.selected_images"
80,204466 [sql] /build/darktable-w3LGls/darktable-3.0.0/src/common/collection.c:834, function dt_collection_get(): prepare "SELECT id FROM main.selected_images AS s JOIN (SELECT DISTINCT mi.id FROM images AS mi WHERE   (flags & 256) != 256  AND  (1=1 AND (film_id IN (SELECT id FROM main.film_rolls WHERE folder LIKE '/home/anarcat/Photos/2019/%')) AND (id IN (SELECT imgid FROM main.tagged_images AS a JOIN data.tags AS b ON a.tagid = b.id WHERE name LIKE 'calendes'))) AND (group_id = -1 OR id IN (SELECT id FROM (SELECT id, MIN(ABS(id-group_id)*2 + CASE WHEN (id-group_id) < 0 THEN 1 ELSE 0 END) FROM main.images WHERE   (flags & 256) != 256  AND  (1=1 AND (film_id IN (SELECT id FROM main.film_rolls WHERE folder LIKE '/home/anarcat/Photos/2019/%')) AND (id IN (SELECT imgid FROM main.tagged_images AS a JOIN data.tags AS b ON a.tagid = b.id WHERE name LIKE 'calendes'))) GROUP BY group_id))) OR (id = -1) ORDER BY datetime_taken, filename , filename, version LIMIT ?1, ?2) AS mi WHERE mi.id = s.imgid LIMIT -1, ?3"
80,225655 [sql] /build/darktable-w3LGls/darktable-3.0.0/src/common/image.c:165, function dt_image_film_roll_directory(): prepare "SELECT folder FROM main.film_rolls WHERE id = ?1"
80,229728 [sql] /build/darktable-w3LGls/darktable-3.0.0/src/libs/metadata.c:131, function update(): prepare "SELECT COUNT(*) FROM main.selected_images"
80,229789 [sql] /build/darktable-w3LGls/darktable-3.0.0/src/libs/metadata.c:137, function update(): prepare "SELECT key, value, COUNT(id) AS ct FROM main.meta_data WHERE id IN (SELECT imgid FROM main.selected_images) GROUP BY key, value ORDER BY value"
80,230122 [sql] /build/darktable-w3LGls/darktable-3.0.0/src/libs/metadata_view.c:231, function _metadata_view_update_values(): prepare "SELECT imgid FROM main.selected_images LIMIT 1"
80,230154 [sql] /build/darktable-w3LGls/darktable-3.0.0/src/common/image.c:181, function dt_image_film_roll(): prepare "SELECT folder FROM main.film_rolls WHERE id = ?1"
80,230363 [sql] /build/darktable-w3LGls/darktable-3.0.0/src/common/image.c:226, function dt_image_full_path(): prepare "SELECT folder || '/' || filename FROM main.images i, main.film_rolls f WHERE i.film_id = f.id and i.id = ?1"
80,230763 [sql] /build/darktable-w3LGls/darktable-3.0.0/src/common/metadata.c:305, function dt_metadata_get_xmp(): prepare "SELECT value FROM main.meta_data WHERE id = ?1 AND key = ?2 ORDER BY value"
80,230803 [sql] /build/darktable-w3LGls/darktable-3.0.0/src/common/metadata.c:305, function dt_metadata_get_xmp(): prepare "SELECT value FROM main.meta_data WHERE id = ?1 AND key = ?2 ORDER BY value"
80,230840 [sql] /build/darktable-w3LGls/darktable-3.0.0/src/common/metadata.c:305, function dt_metadata_get_xmp(): prepare "SELECT value FROM main.meta_data WHERE id = ?1 AND key = ?2 ORDER BY value"
80,230879 [sql] /build/darktable-w3LGls/darktable-3.0.0/src/common/tags.c:604, function dt_set_darktable_tags(): prepare "SELECT COUNT(*) FROM memory.darktable_tags"
80,230897 [sql] /build/darktable-w3LGls/darktable-3.0.0/src/common/tags.c:634, function dt_tag_get_attached(): prepare "SELECT DISTINCT T.id, T.name, T.flags, T.synonyms, 1 AS inb FROM main.tagged_images AS I JOIN data.tags T on T.id = I.tagid WHERE I.imgid = 35464 AND T.id NOT IN memory.darktable_tags ORDER BY T.name"
80,230949 [sql] /build/darktable-w3LGls/darktable-3.0.0/src/common/tags.c:1176, function dt_selected_images_count(): prepare "SELECT count(*) FROM main.selected_images"
80,231117 [sql] /build/darktable-w3LGls/darktable-3.0.0/src/common/tags.c:604, function dt_set_darktable_tags(): prepare "SELECT COUNT(*) FROM memory.darktable_tags"
80,231134 [sql] /build/darktable-w3LGls/darktable-3.0.0/src/common/tags.c:647, function dt_tag_get_attached(): prepare "SELECT DISTINCT I.tagid, T.name, T.flags, T.synonyms, COUNT(DISTINCT S.imgid) AS inb FROM main.selected_images AS S LEFT JOIN main.tagged_images AS I ON I.imgid = S.imgid LEFT JOIN data.tags AS T ON T.id = I.tagid WHERE T.id NOT IN memory.darktable_tags GROUP BY I.tagid ORDER by T.name"
80,231189 [sql] /build/darktable-w3LGls/darktable-3.0.0/src/common/tags.c:1176, function dt_selected_images_count(): prepare "SELECT count(*) FROM main.selected_images"
80,231838 [lighttable] image expose took 0,0005 sec
80,232348 [lighttable] image expose took 0,0005 sec
[... repeated a bunch of times...]

Eventually, this would stop and show something like:

[mipmap_cache] thumbs fill 6,05/954,00 MB (0,63%)
[mipmap_cache] float fill 0/8 slots (0,00%)
[mipmap_cache] full  fill 1/8 slots (12,50%)
[mipmap_cache] level | near match | miss | stand-in | fetches | total rq
[mipmap_cache] thumb |   3,92% |   3,92% |   -nan%  |   0,00% | 100,00%
[mipmap_cache] float |   -nan% |   -nan% |   -nan%  |   0,00% |   0,00%
[mipmap_cache] full  |   -nan% |   -nan% |   -nan%  | 100,00% |   0,00%

Is it some cache that doesn’t get filled in? Or the database upgrade that’s not finished? Am I doing something wrong doctor?

Thanks!

paperdigits · January 5, 2020, 10:46pm

Have you tried starting with an empty db and cache? That eliminate any problems related to upgrading the db and preferences

priort · January 6, 2020, 5:27am

Sounds like its importing your files…did you install in a new directory…maybe its reimporting all your files…

anarcat · January 6, 2020, 4:45pm

I have not, but I will note that I scrapped my DB directory recently (although before the 3.0 upgrade), does that count?

I did not. What do you mean “importing your files”? Is that a new feature in 3.0?

I have run darktable-generate-cache -m 4 here (which adds a whopping 12GB of disk usage!) to see if that would solve the problem, and it doesn’t look like it. At least DT spins up the CPU like a madman on start and it settles down after. But maybe it was doing that thumbnail generation, because after startup, the CPU doesn’t seem to spin up as much anymore.

What I find strange is that DT used to lazily load those thumbnails. It wouldn’t go around generating all those images if it didn’t need… Is that something that changed in 3.0 that it suddenly thinks it’s a good idea to do the equivalent of darktable-generate-cache in the background?

I’d like to stress that this feels like a regression, something that didn’t happen before the upgrade… I can’t help but think the lighttable changes have something to do with this…

paperdigits · January 6, 2020, 5:28pm

I would say no, I’d just pass --library /tmp/db.db and --data /tmp/data.db or something like that. If the CPU use persists, then you’ve narrowed things down.