[import module /sql] import additional directory causes dt to stall

[AxelG-DE]

Describe the bug

First of all: I have a little cold, so if there is inconsistency (or toooo long explanation) in my report, maybe related, as my concentration capability is low... BIG SORRY

When (trying to) importing an additional directory (with my Play Raw pics), dt including the gui stalls severely, so that I had to sigkill dt after 10 minutes or more (and I did restore the *.db from backup after each sigkill)

What I mean with gui stalls, please see screenshot below. "stall" means one one cpu-core loads to ~100% and no other things can be done on dt (other than creating nice screen-art by frozen gui, see below)

One default bug-report-analysis is to check with new config-dir. To not lose time prior 4.6 (if my issue is a bug at all) I report here prior such test (as I have >90k pictures to import). The result of new cofig-dir will be ammended as soon as possible (I will trigger that import after the initial bug report but then go to bed)

Background / additioinal content @jenshannoschwalm asked me on IRC to report my file-system or directory situation:

• my pics are at /home/gerber/DATA/Bilder 2.4TB in size (was a separate disk in the past mounted to ~/DATA)

• for historical reasons I import the soft link: /home/gerber/Bilder

• this DATA folder is on an lvm with lvm-cache (old SSD) /dev/mapper/vg01-home--DATA on /home/gerber/DATA type ext4 (rw,nosuid,nodev,relatime,stripe=56)

• My Play RAWs are here: /home/Datengrab/Datengrab_Bilder/PlayRAW with 2.1G

• Other RAWs from friends are on level up in parallel to Play Raw at /home/Datengrab/Datengrab_Bilder with 13G in total

• this folder is on the same physical HDD on lvm with lvm-cache on /dev/mapper/vg01-Datengrab on /home/Datengrab type ext4 (rw,nosuid,nodev,relatime,stripe=32)

• ~/ with ~/.config and ~/.cache is on an nvme with xfs

Permissions are fine!

Issue just clicking on import/add to library makes dt and gui stall for 18s and even longer if "ignore-non-raw images" is not ticked. Ticking that takes a fortune again.

-d all -d perf delivers many, many lines like this: 70.8641 [sql] /home/gerber/.local/git/darktable/src/common/film.c:102, function dt_film_get_id(): prepare "SELECT id FROM main.film_rolls WHERE folder = ?1 Sometimes even that stalls for minutes and suddenly creates another gazillions of such lines

in "places" of the "add to library" I do have old and partially orphaned directories. Clicking on those leads to a total hang for ever.

Just now I was patient and "Datengrab_Bilder" got added to places, but what I see in the proposed imports (the file list) makes no any sense to me (I discover this right now while typing this issue) that is all garbage IMHO.

1. I will not import mails
2. DATA/Bilder is in my homedir but I want to import "Datengrab_Bilder"

At this point I cancel. The output of -d all -d perf is below

Steps to reproduce

As described above

1. Go to lighttable
2. click on import / add to library
3. change to another (accessible), in my case different mount point

See error

Expected behavior

be as swift as it was before (open the import dialog lasted ~5s or so IIRC)

Logfile | Screenshot | Screencast

Output of -d all -d perf dt-stall.txt.zip

Gui frozen/stalled

Commit

No response

Where did you obtain darktable from?

self compiled

darktable version

darktable 4.5.0+1428~g81f018af64

What OS are you using?

Linux

What is the version of your OS?

gentoo

Describe your system?

• darktable version : 4.5.0-1428-g81f018af64
• OS : Linux - kernel 6.6.6-gentoo
• Distro : Gentoo Base System release 2.14
• Processor : Intel(R) Core(TM) i9-9900K CPU @ 3.60GHz
• Memory : 32 GB (4 x 8 GB) + 5GB Swap
• Graphics card0 : NVIDIA GeForce GTX 1060 6GB
• Graphics card1 : NVIDIA GeForce RTX 2070 SUPER
• Graphics driver : nvidia-drivers-535.129.03
• OpenCL installed : Yes (opencl-headers-2023.04.17)
• OpenCL activated : Yes
• Xorg : xorg-server-21.1.9
• Desktop : KDE 5
• GTK+ : gtk+-3.24.38
• gcc : 13.2.1_p20230826
• cflags : CMAKE_FLAGS="-march=native-O2-mtune=native-pipe"
• CMAKE_BUILD_TYPE : "Release"

Are you using OpenCL GPU in darktable?

Yes

If yes, what is the GPU card and driver?

pls see above

Please provide additional context if applicable. You can attach files too, but might need to rename to .txt or .zip

please see above

[AxelG-DE]

I am just starting to import into new config-dir and behaviour is likely same frozen gui

[AxelG-DE]

20.5748 [sql] /home/gerber/.local/git/darktable/src/common/film.c:102, function dt_film_get_id(): prepare "SELECT id FROM main.film_rolls WHERE folder = ?1"
    20.5749 [sql] /home/gerber/.local/git/darktable/src/common/film.c:102, function dt_film_get_id(): prepare "SELECT id FROM main.film_rolls WHERE folder = ?1"
    20.5750 [sql] /home/gerber/.local/git/darktable/src/common/film.c:102, function dt_film_get_id(): prepare "SELECT id FROM main.film_rolls WHERE folder = ?1"
    20.5751 [sql] /home/gerber/.local/git/darktable/src/common/film.c:102, function dt_film_get_id(): prepare "SELECT id FROM main.film_rolls WHERE folder = ?1"
    20.5751 [sql] /home/gerber/.local/git/darktable/src/common/film.c:102, function dt_film_get_id(): prepare "SELECT id FROM main.film_rolls WHERE folder = ?1"
    20.5752 [sql] /home/gerber/.local/git/darktable/src/common/film.c:102, function dt_film_get_id(): prepare "SELECT id FROM main.film_rolls WHERE folder = ?1"
    20.5756 [sql] /home/gerber/.local/git/darktable/src/common/film.c:102, function dt_film_get_id(): prepare "SELECT id FROM main.film_rolls WHERE folder = ?1"
    20.5757 [sql] /home/gerber/.local/git/darktable/src/common/film.c:102, function dt_film_get_id(): prepare "SELECT id FROM main.film_rolls WHERE folder = ?1"
    20.5840 [sql] /home/gerber/.local/git/darktable/src/common/film.c:102, function dt_film_get_id(): prepare "SELECT id FROM main.film_rolls WHERE folder = ?1"
    20.5841 [sql] /home/gerber/.local/git/darktable/src/common/film.c:102, function dt_film_get_id(): prepare "SELECT id FROM main.film_rolls WHERE folder = ?1"
    20.5842 [sql] /home/gerber/.local/git/darktable/src/common/film.c:102, function dt_film_get_id(): prepare "SELECT id FROM main.film_rolls WHERE folder = ?1"
    20.5842 [sql] /home/gerber/.local/git/darktable/src/common/film.c:102, function dt_film_get_id(): prepare "SELECT id FROM main.film_rolls WHERE folder = ?1"
    20.5844 [sql] /home/gerber/.local/git/darktable/src/common/film.c:102, function dt_film_get_id(): prepare "SELECT id FROM main.film_rolls WHERE folder = ?1"
    20.5844 [sql] /home/gerber/.local/git/darktable/src/common/film.c:102, function dt_film_get_id(): prepare "SELECT id FROM main.film_rolls WHERE folder = ?1"
    20.5847 [sql] /home/gerber/.local/git/darktable/src/common/film.c:102, function dt_film_get_id(): prepare "SELECT id FROM main.film_rolls WHERE folder = ?1"
    20.5849 [sql] /home/gerber/.local/git/darktable/src/common/film.c:102, function dt_film_get_id(): prepare "SELECT id FROM main.film_rolls WHERE folder = ?1"
    20.5852 [sql] /home/gerber/.local/git/darktable/src/common/film.c:102, function dt_film_get_id(): prepare "SELECT id FROM main.film_rolls WHERE folder = ?1"
    20.5852 [sql] /home/gerber/.local/git/darktable/src/common/film.c:102, function dt_film_get_id(): prepare "SELECT id FROM main.film_rolls WHERE folder = ?1"
    20.5855 [sql] /home/gerber/.local/git/darktable/src/common/film.c:102, function dt_film_get_id(): prepare "SELECT id FROM main.film_rolls WHERE folder = ?1"
    20.5857 [sql] /home/gerber/.local/git/darktable/src/common/film.c:102, function dt_film_get_id(): prepare "SELECT id FROM main.film_rolls WHERE folder = ?1"
    20.5859 [sql] /home/gerber/.local/git/darktable/src/common/film.c:102, function dt_film_get_id(): prepare "SELECT id FROM main.film_rolls WHERE folder = ?1"
    20.5860 [sql] /home/gerber/.local/git/darktable/src/common/film.c:102, function dt_film_get_id(): prepare "SELECT id FROM main.film_rolls WHERE folder = ?1"
    20.5861 [sql] /home/gerber/.local/git/darktable/src/common/film.c:102, function dt_film_get_id(): prepare "SELECT id FROM main.film_rolls WHERE folder = ?1"
    20.5862 [sql] /home/gerber/.local/git/darktable/src/common/film.c:102, function dt_film_get_id(): prepare "SELECT id FROM main.film_rolls WHERE folder = ?1"
    20.5863 [sql] /home/gerber/.local/git/darktable/src/common/film.c:102, function dt_film_get_id(): prepare "SELECT id FROM main.film_rolls WHERE folder = ?1"
    20.5864 [sql] /home/gerber/.local/git/darktable/src/common/film.c:102, function dt_film_get_id(): prepare "SELECT id FROM main.film_rolls WHERE folder = ?1"
    20.5864 [sql] /home/gerber/.local/git/darktable/src/common/film.c:102, function dt_film_get_id(): prepare "SELECT id FROM main.film_rolls WHERE folder = ?1"
    20.5865 [sql] /home/gerber/.local/git/darktable/src/common/film.c:102, function dt_film_get_id(): prepare "SELECT id FROM main.film_rolls WHERE folder = ?1"
    20.5866 [sql] /home/gerber/.local/git/darktable/src/common/film.c:102, function dt_film_get_id(): prepare "SELECT id FROM main.film_rolls WHERE folder = ?1"
    20.5868 [sql] /home/gerber/.local/git/darktable/src/common/film.c:102, function dt_film_get_id(): prepare "SELECT id FROM main.film_rolls WHERE folder = ?1"
    20.5868 [sql] /home/gerber/.local/git/darktable/src/common/film.c:102, function dt_film_get_id(): prepare "SELECT id FROM main.film_rolls WHERE folder = ?1"
    20.5869 [sql] /home/gerber/.local/git/darktable/src/common/film.c:102, function dt_film_get_id(): prepare "SELECT id FROM main.film_rolls WHERE folder = ?1"
    20.5871 [sql] /home/gerber/.local/git/darktable/src/common/film.c:102, function dt_film_get_id(): prepare "SELECT id FROM main.film_rolls WHERE folder = ?1"
    20.5872 [sql] /home/gerber/.local/git/darktable/src/common/film.c:102, function dt_film_get_id(): prepare "SELECT id FROM main.film_rolls WHERE folder = ?1"
    20.5874 [sql] /home/gerber/.local/git/darktable/src/common/film.c:102, function dt_film_get_id(): prepare "SELECT id FROM main.film_rolls WHERE folder = ?1"
    20.5884 [sql] /home/gerber/.local/git/darktable/src/common/film.c:102, function dt_film_get_id(): prepare "SELECT id FROM main.film_rolls WHERE folder = ?1"
    20.5885 [sql] /home/gerber/.local/git/darktable/src/common/film.c:102, function dt_film_get_id(): prepare "SELECT id FROM main.film_rolls WHERE folder = ?1"
    20.5885 [sql] /home/gerber/.local/git/darktable/src/common/film.c:102, function dt_film_get_id(): prepare "SELECT id FROM main.film_rolls WHERE folder = ?1"
    20.5886 [sql] /home/gerber/.local/git/darktable/src/common/film.c:102, function dt_film_get_id(): prepare "SELECT id FROM main.film_rolls WHERE folder = ?1"
    20.5887 [sql] /home/gerber/.local/git/darktable/src/common/film.c:102, function dt_film_get_id(): prepare "SELECT id FROM main.film_rolls WHERE folder = ?1"

[AxelG-DE]

I think I can stop here already and bring my original .config and .cache in place again

[gi-man]

I see a module called selected images path . That's not part of dt. Is that a LUA module?

[wpferguson]

Yes, it's from official/image_path_in_ui.lua

EDIT:

It shows the path for a selected image

[jenshannoschwalm]

@TurboGit and @victoryforce i looked at this for short and from my understanding it might be related to checking to include all non-raws instead of jpegs. Unfortunately I am very short of time, could you check?

1. While checking for another group header we now would now have to exclude all non-raws.
2. While traversing all files we might want to exclude hidden files or backups (starting with '.' or "~")?

[TurboGit]

@victoryforce : If you have some spare cycle, please have a look. Personally I won't have time before the full freeze in about 30h.

Looking at the report I'm wondering if there is not a recursive directory structure with some symlinks. I was not able to reproduce on my side anyway.

[TurboGit]

@AxelG-DE : BTW, is that a regression compared to 4.4.2? If you could check that would be very helpful. TIA.

[jenshannoschwalm]

I also couldn't reproduce so asking the OP for dirs. @AxelG-DE could you provide a tree for the "hanging" dirs?

[zisoft]

My guess here is a circular symbolic link from a directory to a directory somewhere higher in the same tree.

[AxelG-DE]

@AxelG-DE : BTW, is that a regression compared to 4.4.2? If you could check that would be very helpful. TIA.

@TurboGit Just a few weeks ago I have re-imported all my 92k photos and all worked like a charm. In July and October I was on trips to Paris and Berlin and both set I imported with no issues. Hence I said on IRC/Matrix, yes, that I do see a regression and I will start now with revert or bisect around 8c1f7bbc9882f5fac80f509de8d10e985bd5ba88 and d67d557f0a7c9c928ae1faf78d7a6b7285a31390.

@AxelG-DE could you provide a tree for the "hanging" dirs?

@jenshannoschwalm yesterday I put ~/.config/darktable and ~/.cache/darktable out of the way and wanted to import my standard picture dir and dt stalled for many minutes (I sigkilled afterwards). When you say "provide a tree" you mean 'find ./' ? Technically I could, however, I would disclose a lot due to my naming scheme. Doesn't feel nice. I could give it to you personally instead, hence my approach on IRC-PM. However you said you have limited time, so I don't wanna put additional load to you.

I did check on my own. I typically do not use special characters, but I do have an Archive of my Phone-pics in the same dir and there I found pics with Chinese characters and at least one file with this name: ./Archiv/Samsung_S3/Sicherheitskopie/Recovered_Pictures_2014-04-29/[000139].jpg that is obviously odd with the [ ] but both of those files they are there since years.

My guess here is a circular symbolic link from a directory to a directory somewhere higher in the same tree.

@zisoft no, I do not have such weird link structure and as I said, my picture dear is years old.

if you worry about two times "Bilder"... nope, that one is a Desktop-Icon

[AxelG-DE]

4.4.2 is rather o.k. with importing, but even this is darktable 4.5.0+789~g07e1b26d98-dirty shows the effect (donno why is called dirty, I never fiddled with the code)

I will have a fresh clone and try again

[victoryforce]

it might be related to checking to include all non-raws instead of jpegs.

@victoryforce : If you have some spare cycle, please have a look.

@TurboGit Regarding the PR that replaced ignoring jpegs with ignoring non-raws, I looked carefully at the changes made and can't imagine how this could cause such a regression.

@AxelG-DE Ah, I noticed your comment that the regression was already present in a much earlier git snapshot (4.5.0+789), so it's definitely not from replacing the ignore criteria on import.

[TurboGit]

@victoryforce : Indeed, my guess was wrong. @AxelG-DE is doing a bisect as we speak, so we'll know the culprit soon hopefully.

[AxelG-DE]

hopefully.... bisect is hard, as db-updates forces me to del the dbs and also everytime dt stalls, I struggle, how long to wait

I do face the scenario, that one cpu-core is fully loaded, no CLI output at all, no HDD-io, GUI frozen...

[AxelG-DE]

BTW: I do the bisect with a complete fresh .config and .cache :-/ and I am as much in the past already, that I get more and more doubts :-(

can it be, my sqlite is broken???

[TurboGit]

can it be, my sqlite is broken???

Could be, at this point no dev have been able to reproduce and the issue is not understood...

[AxelG-DE]

here we go (and especially the last two steps felt quite consistent as the crashes got more severe or stalls happened even earlier in the testing)

0122fd92b09d1a21fbaa0fd132cec14e2a1633e8 is the first bad commit
commit 0122fd92b09d1a21fbaa0fd132cec14e2a1633e8
Author: Pascal Obry <[email protected]>
Date:   Sat Sep 30 22:15:51 2023 +0200

    Ensure ui_last/import_last_directory is sanitized.
    
    Fix a possible crash as reported in #15334.

 data/darktableconfig.xml.in         |  4 ++--
 src/control/conf.c                  | 22 ++++++++++++++++++++++
 src/control/conf.h                  |  2 ++
 src/libs/import.c                   | 12 ++++++++----
 tools/generate_darktablerc_conf.xsl | 16 +++++++++-------
 5 files changed, 43 insertions(+), 13 deletions(-)

[AxelG-DE]

I started with sqlite-3.43.2 finally also tested 3.42.0 and 3.44.2

all with the same result

[AxelG-DE]

just for the record. When ever I stall dt by opening the import dialog and try to change a folder to a different one, the Gui freezes and also the CLI output stops usually at approx 21s and only those sql-lines show up, even I started with -d all. Typically I wait for several minutes before I sigkill....

[AxelG-DE]

$ git bisect log
git bisect start
# Status: warte auf guten und schlechten Commit
# good: [e44f1001a805324ca60fb7dba99764de53b04902] RELEASE_NOTES.md: Initialize for 4.6 release.
git bisect good e44f1001a805324ca60fb7dba99764de53b04902
# Status: warte auf schlechten Commit, 1 guter Commit bekannt
# bad: [88819c341e0328ab570ea2ab1c2e3ebb1ef0519d] Update ja.po (#15866)
git bisect bad 88819c341e0328ab570ea2ab1c2e3ebb1ef0519d
# good: [c2ca752f1f647ea40ad24e31b6df2ed2bd953b60] control & jobs maintenance
git bisect good c2ca752f1f647ea40ad24e31b6df2ed2bd953b60
# bad: [dfd848417b155ad9e41d3565e9816e6a49b6533c] fix snapshots with different crop
git bisect bad dfd848417b155ad9e41d3565e9816e6a49b6533c
# bad: [8f7465fa5dd7000d19199b1a85d932ddbd05ecad] Extended GPS coordinate import to support just decimal value in .xmp file (#15443)
git bisect bad 8f7465fa5dd7000d19199b1a85d932ddbd05ecad
# bad: [0397d6a1164b3282a72aed3d798b2c78d4b6fc94] Merge pull request #15401 from victoryforce/rating-range-filter-optimize-tooltip
git bisect bad 0397d6a1164b3282a72aed3d798b2c78d4b6fc94
# bad: [f67e6db257028b59b3112f52803a22a6e2056149] image: Minor code simplification for _any_altered_data.
git bisect bad f67e6db257028b59b3112f52803a22a6e2056149
# bad: [dbf6b68ef588e98b17c6cc127baa65c4db2092f4] Merge pull request #15364 from dterrahe/refactor_zoom
git bisect bad dbf6b68ef588e98b17c6cc127baa65c4db2092f4
# bad: [646b9e3f80cb33a8549ff3538d541f9a1e891e08] reduce cairo scale in post_expose
git bisect bad 646b9e3f80cb33a8549ff3538d541f9a1e891e08
# good: [4fc03872b0d11de76751ef535f325ba1f72801b7] RELEASE_NOTES.md: Add some entries for 4.6.
git bisect good 4fc03872b0d11de76751ef535f325ba1f72801b7
# good: [af0975cca0433995fc35d26eef14746d78095a4b] Unbreak build env preparation by removing the non-installable openexr package
git bisect good af0975cca0433995fc35d26eef14746d78095a4b
# bad: [07e1b26d987101daa2439daffaa53d17f22ddd80] Updates to pt_BR
git bisect bad 07e1b26d987101daa2439daffaa53d17f22ddd80
# bad: [0122fd92b09d1a21fbaa0fd132cec14e2a1633e8] Ensure ui_last/import_last_directory is sanitized.
git bisect bad 0122fd92b09d1a21fbaa0fd132cec14e2a1633e8
# first bad commit: [0122fd92b09d1a21fbaa0fd132cec14e2a1633e8] Ensure ui_last/import_last_directory is sanitized.

[TurboGit]

Hum... one of my commit... that's not possible I never introduce bug :)

What's your current value for ui_last/import_last_directory ?

[TurboGit]

@AxelG-DE : Thanks for the hard work, this certainly will help fixing the issue.

Can you check if #15870 works on your side? TIA.

[AxelG-DE]

I had delted my former comment as I found an error during my this morning tests, sorry!!!

[AxelG-DE]

I will repeat the test!

[AxelG-DE]

Hum... one of my commit... that's not possible I never introduce bug :)

What's your current value for ui_last/import_last_directory ?

We are not sure yet, it is a bug :-) :-)

import_last_directory was "/home/gerber" which is odd "/home/gerber/Bilder". I am not that stupid to import my entire home-dir.

Meanwhile we are online talking on IRC.

For docu-purpose: commit a9615b3292 almost no improvement commit b4cce7b795 is way better and recovers much faster (still I can make dt stall for <300s)

For the first attempt in selecting a folder it already takes ~30s idle time, where is 100% load on one core and no IO

[jenshannoschwalm]

I think we fallback to home if the last config dir is not a dir!

#15354

[jenshannoschwalm]

We should avoid traversing hidden directories I think.

[TurboGit]

We should avoid traversing hidden directories I think.

That's already the case.

[jenshannoschwalm]

That's already the case.

I thought so too but in the log screenshot we see files tested in /home/gerber/.local... and .local should be avoided as hidden.