Geeqie image tests fail with xdg-desktop-portal package installed

[xsdg]

Setup (please complete the following information):

• Distribution: [e.g. Ubuntu] Debian
• Distribution release: [e.g. 20.04] Unstable
• Geeqie version [geeqie --version]: e9d01b6

Describe the bug
First noticed by @caclark after my isolate-test.sh simplification in 59b915e

When the xdg-desktop-portal package is not installed, the image tests work fine. When that package is installed, the tests fail.

To reproduce

$mkdir build
$meson setup -D unit_tests=enabled build
[...]
$meson test -C build
[...]
Ok:                 1069
Expected Fail:      1   
Fail:               75  
Unexpected Pass:    0   
Skipped:            0   
Timeout:            0   

Unexpected behavior

=================================== 1/1145 ===================================
test:         geeqie:functional / Basic test
start time:   18:56:45
duration:     0.53s
result:       exit status 1
command:      MALLOC_PERTURB_=86 /home/xsdg/files/compile/photos/gitqi/scripts/isolate-test.sh /usr/bin/xvfb-run --auto-servernum /home/xsdg/files/compile/photos/gitqi/build/src/geeqie --ver
sion
----------------------------------- stdout -----------------------------------
would run dbus-run-session -- /usr/bin/xvfb-run --auto-servernum /home/xsdg/files/compile/photos/gitqi/build/src/geeqie --version
Creating Geeqie dir:/tmp/tmp.uc6WJqki5w/.config/geeqie

Creating Geeqie dir:/tmp/tmp.uc6WJqki5w/.local/share/geeqie/collections

Creating Geeqie dir:/tmp/tmp.uc6WJqki5w/.cache/geeqie/thumbnails

Creating Geeqie dir:/tmp/tmp.uc6WJqki5w/.local/share/geeqie/metadata

Creating Geeqie dir:/tmp/tmp.uc6WJqki5w/.config/geeqie/layouts

Geeqie 2.5 GTK3
----------------------------------- stderr -----------------------------------
Variables in isolated environment:
G_DEBUG=fatal-critical
HOME=/tmp/tmp.uc6WJqki5w
XDG_CONFIG_HOME=/tmp/tmp.uc6WJqki5w/.config
XDG_RUNTIME_DIR=/tmp/tmp.uc6WJqki5w/.runtime
DBUS_SESSION_BUS_ADDRESS=unix:path=/tmp/dbus-p7g38Fl5iH,guid=bf6d39400a97edc27d3ff46b67212fed

MESA: error: ZINK: vkCreateInstance failed (VK_ERROR_INCOMPATIBLE_DRIVER)
glx: failed to create drisw screen
failed to load driver: zink

(geeqie:910949): dbind-WARNING **: 18:56:45.335: AT-SPI: Error retrieving accessibility bus address: org.freedesktop.DBus.Error.ServiceUnknown: The name org.a11y.Bus was not provided by any 
.service files
dbus-daemon[910712]: [session uid=1000 pid=910712] Activating service name='org.freedesktop.portal.Desktop' requested by ':1.0' (uid=1000 pid=910949 comm="/home/xsdg/files/compile/photos/git
qi/build/src/ge")
dbus-daemon[910712]: [session uid=1000 pid=910712] Activating service name='org.freedesktop.portal.Documents' requested by ':1.2' (uid=1000 pid=911167 comm="/usr/libexec/xdg-desktop-portal")
dbus-daemon[910712]: [session uid=1000 pid=910712] Activating service name='org.freedesktop.impl.portal.PermissionStore' requested by ':1.3' (uid=1000 pid=911178 comm="/usr/libexec/xdg-docum
ent-portal")
dbus-daemon[910712]: [session uid=1000 pid=910712] Successfully activated service 'org.freedesktop.impl.portal.PermissionStore'
dbus-daemon[910712]: [session uid=1000 pid=910712] Successfully activated service 'org.freedesktop.portal.Documents'
Ignoring invalid max threads value 4294967295 > max (100000).

(/usr/libexec/xdg-desktop-portal:911167): xdg-desktop-portal-WARNING **: 18:56:45.386: Failed to load RealtimeKit property: GDBus.Error:org.freedesktop.DBus.Error.ServiceUnknown: The name org.freedesktop.RealtimeKit1 was not provided by any .service files

(/usr/libexec/xdg-desktop-portal:911167): xdg-desktop-portal-WARNING **: 18:56:45.387: Failed to load RealtimeKit property: GDBus.Error:org.freedesktop.DBus.Error.ServiceUnknown: The name org.freedesktop.RealtimeKit1 was not provided by any .service files

(/usr/libexec/xdg-desktop-portal:911167): xdg-desktop-portal-WARNING **: 18:56:45.387: Failed to load RealtimeKit property: GDBus.Error:org.freedesktop.DBus.Error.ServiceUnknown: The name org.freedesktop.RealtimeKit1 was not provided by any .service files

(/usr/libexec/xdg-desktop-portal:911167): xdg-desktop-portal-WARNING **: 18:56:45.387: No skeleton to export
dbus-daemon[910712]: [session uid=1000 pid=910712] Successfully activated service 'org.freedesktop.portal.Desktop'
rm: cannot remove '/tmp/tmp.uc6WJqki5w/.runtime/doc/by-app': Operation not permitted
==============================================================================

Here's another example, with a different-seeming failure mode:

=================================== 6/1145 ===================================
test:         geeqie:functional+image / Image_ JPG_MINOLTA_RD175.JPG
start time:   18:56:45
duration:     4.38s
result:       exit status 1
command:      MALLOC_PERTURB_=248 /home/xsdg/files/compile/photos/gitqi/scripts/isolate-test.sh /home/xsdg/files/compile/photos/gitqi/scripts/image-test.py /home/xsdg/files/compile/photos/gi
tqi/build/src/geeqie /home/xsdg/files/compile/photos/gitqi/build/test-images.p/images/JPG_MINOLTA_RD175.JPG
----------------------------------- stdout -----------------------------------
would run dbus-run-session -- /home/xsdg/files/compile/photos/gitqi/scripts/image-test.py /home/xsdg/files/compile/photos/gitqi/build/src/geeqie /home/xsdg/files/compile/photos/gitqi/build/t
est-images.p/images/JPG_MINOLTA_RD175.JPG
Creating Geeqie dir:/tmp/tmp.Nj4qp7Qe0O/.config/geeqie

Creating Geeqie dir:/tmp/tmp.Nj4qp7Qe0O/.local/share/geeqie/collections

Creating Geeqie dir:/tmp/tmp.Nj4qp7Qe0O/.cache/geeqie/thumbnails

Creating Geeqie dir:/tmp/tmp.Nj4qp7Qe0O/.local/share/geeqie/metadata

Creating Geeqie dir:/tmp/tmp.Nj4qp7Qe0O/.config/geeqie/layouts

----------------------------------- stderr -----------------------------------
Variables in isolated environment:
G_DEBUG=fatal-critical
HOME=/tmp/tmp.Nj4qp7Qe0O
XDG_CONFIG_HOME=/tmp/tmp.Nj4qp7Qe0O/.config
XDG_RUNTIME_DIR=/tmp/tmp.Nj4qp7Qe0O/.runtime
DBUS_SESSION_BUS_ADDRESS=unix:path=/tmp/dbus-W2zLxdlkhu,guid=1f8dfad6ebedd6e4e26425b867212fed

MESA: error: ZINK: vkCreateInstance failed (VK_ERROR_INCOMPATIBLE_DRIVER)
glx: failed to create drisw screen
failed to load driver: zink

(geeqie:911162): dbind-WARNING **: 18:56:45.443: AT-SPI: Error retrieving accessibility bus address: org.freedesktop.DBus.Error.ServiceUnknown: The name org.a11y.Bus was not provided by any .service files
dbus-daemon[910796]: [session uid=1000 pid=910796] Activating service name='org.freedesktop.portal.Desktop' requested by ':1.0' (uid=1000 pid=911162 comm="/home/xsdg/files/compile/photos/gitqi/build/src/ge")
dbus-daemon[910796]: [session uid=1000 pid=910796] Activating service name='org.freedesktop.portal.Documents' requested by ':1.2' (uid=1000 pid=911364 comm="/usr/libexec/xdg-desktop-portal")
dbus-daemon[910796]: [session uid=1000 pid=910796] Activating service name='org.freedesktop.impl.portal.PermissionStore' requested by ':1.3' (uid=1000 pid=911376 comm="/usr/libexec/xdg-document-portal")
dbus-daemon[910796]: [session uid=1000 pid=910796] Successfully activated service 'org.freedesktop.impl.portal.PermissionStore'
dbus-daemon[910796]: [session uid=1000 pid=910796] Successfully activated service 'org.freedesktop.portal.Documents'
Ignoring invalid max threads value 4294967295 > max (100000).

(/usr/libexec/xdg-desktop-portal:911364): xdg-desktop-portal-WARNING **: 18:56:45.506: Failed to load RealtimeKit property: GDBus.Error:org.freedesktop.DBus.Error.ServiceUnknown: The name org.freedesktop.RealtimeKit1 was not provided by any .service files

(/usr/libexec/xdg-desktop-portal:911364): xdg-desktop-portal-WARNING **: 18:56:45.507: Failed to load RealtimeKit property: GDBus.Error:org.freedesktop.DBus.Error.ServiceUnknown: The name org.freedesktop.RealtimeKit1 was not provided by any .service files

(/usr/libexec/xdg-desktop-portal:911364): xdg-desktop-portal-WARNING **: 18:56:45.507: Failed to load RealtimeKit property: GDBus.Error:org.freedesktop.DBus.Error.ServiceUnknown: The name org.freedesktop.RealtimeKit1 was not provided by any .service files

(/usr/libexec/xdg-desktop-portal:911364): xdg-desktop-portal-WARNING **: 18:56:45.507: No skeleton to export
dbus-daemon[910796]: [session uid=1000 pid=910796] Successfully activated service 'org.freedesktop.portal.Desktop'
Warning: Failed to convert Exif.Photo.DateTimeOriginal to Xmp.photoshop.DateCreated, unable to parse '19ff:1f:3f 3f:7f:00'
Warning: Failed to convert Exif.Photo.DateTimeDigitized to Xmp.xmp.CreateDate, unable to parse '19ff:1f:3f 3f:7f:00'
rm: cannot remove '/tmp/tmp.Nj4qp7Qe0O/.runtime/doc': Is a directory
==============================================================================

Expected behavior
Without xdg-desktop-portal installed, these two look like the following:

=================================== 1/1145 ===================================
test:         geeqie:functional / Basic test
start time:   19:11:45
duration:     0.62s
result:       exit status 0
command:      MALLOC_PERTURB_=19 /home/xsdg/files/compile/photos/gitqi/scripts/isolate-test.sh /usr/bin/xvfb-run --auto-servernum /home/xsdg/files/compile/photos/gitqi/build/src/geeqie --version
----------------------------------- stdout -----------------------------------
would run dbus-run-session -- /usr/bin/xvfb-run --auto-servernum /home/xsdg/files/compile/photos/gitqi/build/src/geeqie --version
Creating Geeqie dir:/tmp/tmp.6NMXzE2Pqp/.config/geeqie

Creating Geeqie dir:/tmp/tmp.6NMXzE2Pqp/.local/share/geeqie/collections

Creating Geeqie dir:/tmp/tmp.6NMXzE2Pqp/.cache/geeqie/thumbnails

Creating Geeqie dir:/tmp/tmp.6NMXzE2Pqp/.local/share/geeqie/metadata

Creating Geeqie dir:/tmp/tmp.6NMXzE2Pqp/.config/geeqie/layouts

Geeqie 2.5 GTK3
----------------------------------- stderr -----------------------------------
Variables in isolated environment:
G_DEBUG=fatal-critical
HOME=/tmp/tmp.6NMXzE2Pqp
XDG_CONFIG_HOME=/tmp/tmp.6NMXzE2Pqp/.config
XDG_RUNTIME_DIR=/tmp/tmp.6NMXzE2Pqp/.runtime
DBUS_SESSION_BUS_ADDRESS=unix:path=/tmp/dbus-q1kmuEiE3z,guid=091a8ba83896a9a4900991a567213371

MESA: error: ZINK: vkCreateInstance failed (VK_ERROR_INCOMPATIBLE_DRIVER)
glx: failed to create drisw screen
failed to load driver: zink

(geeqie:935079): dbind-WARNING **: 19:11:45.367: AT-SPI: Error retrieving accessibility bus address: org.freedesktop.DBus.Error.ServiceUnknown: The name org.a11y.Bus was not provided by any .service files
==============================================================================

And the JPG test:

=================================== 5/1145 ===================================
test:         geeqie:functional+image / Image_ JPG_MINOLTA_RD175.JPG
start time:   19:11:45
duration:     4.36s
result:       exit status 0
command:      MALLOC_PERTURB_=53 /home/xsdg/files/compile/photos/gitqi/scripts/isolate-test.sh /home/xsdg/files/compile/photos/gitqi/scripts/image-test.py /home/xsdg/files/compile/photos/gitqi/build/src/geeqie /home/xsdg/files/compile/photos/gitqi/build/test-images.p/images/JPG_MINOLTA_RD175.JPG
----------------------------------- stdout -----------------------------------
would run dbus-run-session -- /home/xsdg/files/compile/photos/gitqi/scripts/image-test.py /home/xsdg/files/compile/photos/gitqi/build/src/geeqie /home/xsdg/files/compile/photos/gitqi/build/test-images.p/images/JPG_MINOLTA_RD175.JPG
Creating Geeqie dir:/tmp/tmp.hO9pzTyohk/.config/geeqie

Creating Geeqie dir:/tmp/tmp.hO9pzTyohk/.local/share/geeqie/collections

Creating Geeqie dir:/tmp/tmp.hO9pzTyohk/.cache/geeqie/thumbnails

Creating Geeqie dir:/tmp/tmp.hO9pzTyohk/.local/share/geeqie/metadata

Creating Geeqie dir:/tmp/tmp.hO9pzTyohk/.config/geeqie/layouts

----------------------------------- stderr -----------------------------------
Variables in isolated environment:
G_DEBUG=fatal-critical
HOME=/tmp/tmp.hO9pzTyohk
XDG_CONFIG_HOME=/tmp/tmp.hO9pzTyohk/.config
XDG_RUNTIME_DIR=/tmp/tmp.hO9pzTyohk/.runtime
DBUS_SESSION_BUS_ADDRESS=unix:path=/tmp/dbus-tO2NVlGP0O,guid=85362adf26759052d7022c0c67213371

MESA: error: ZINK: vkCreateInstance failed (VK_ERROR_INCOMPATIBLE_DRIVER)
glx: failed to create drisw screen
failed to load driver: zink

(geeqie:935087): dbind-WARNING **: 19:11:45.360: AT-SPI: Error retrieving accessibility bus address: org.freedesktop.DBus.Error.ServiceUnknown: The name org.a11y.Bus was not provided by any .service files
Warning: Failed to convert Exif.Photo.DateTimeOriginal to Xmp.photoshop.DateCreated, unable to parse '19ff:1f:3f 3f:7f:00'
Warning: Failed to convert Exif.Photo.DateTimeDigitized to Xmp.xmp.CreateDate, unable to parse '19ff:1f:3f 3f:7f:00'
==============================================================================

[xsdg]

Okay, so I replaced rm -rf with rm -rfv to show how rm progresses through the directory tree. That shows the following:

removed directory '/tmp/tmp.4lL6wQPEf9/.runtime/dbus-1/services'
removed directory '/tmp/tmp.4lL6wQPEf9/.runtime/dbus-1'
rm: cannot remove '/tmp/tmp.4lL6wQPEf9/.runtime/doc': Is a directory
removed '/tmp/tmp.4lL6wQPEf9/.runtime/dconf/user'
removed directory '/tmp/tmp.4lL6wQPEf9/.runtime/dconf'
removed directory '/tmp/tmp.4lL6wQPEf9/.config/geeqie/layouts'
removed '/tmp/tmp.4lL6wQPEf9/.config/geeqie/marks'
removed '/tmp/tmp.4lL6wQPEf9/.config/geeqie/geeqierc.xml'
removed '/tmp/tmp.4lL6wQPEf9/.config/geeqie/history'
removed '/tmp/tmp.4lL6wQPEf9/.config/geeqie/accels'
removed directory '/tmp/tmp.4lL6wQPEf9/.config/geeqie'
removed directory '/tmp/tmp.4lL6wQPEf9/.config/ibus/bus'
removed directory '/tmp/tmp.4lL6wQPEf9/.config/ibus'
removed directory '/tmp/tmp.4lL6wQPEf9/.config'
removed directory '/tmp/tmp.4lL6wQPEf9/.local/share/geeqie/collections'
removed directory '/tmp/tmp.4lL6wQPEf9/.local/share/geeqie/metadata'
removed directory '/tmp/tmp.4lL6wQPEf9/.local/share/geeqie'
removed directory '/tmp/tmp.4lL6wQPEf9/.local/share'
removed directory '/tmp/tmp.4lL6wQPEf9/.local'
removed directory '/tmp/tmp.4lL6wQPEf9/.cache/geeqie/thumbnails'
removed directory '/tmp/tmp.4lL6wQPEf9/.cache/geeqie'
removed directory '/tmp/tmp.4lL6wQPEf9/.cache'

The source for rm is here: https://github.com/coreutils/coreutils/blob/master/src/remove.c

Importantly, recursive rm uses a generator that will DFS-traverse the filesystem, but that will emit twice for every directory, first to recurse, and secondly to delete the directory itself. From the source:

/* This function is called once for every file system object that fts
   encounters.  fts performs a depth-first traversal.
   A directory is usually processed twice, first with fts_info == FTS_D,
   and later, after all of its entries have been processed, with FTS_DP.

So if a directory is created between the FTS_D and FTS_DP phases, we could end up in a situation where rm refuses to delete it. Alternately, if a file is replaced by a directory (or otherwise changes type), then rm could attempt to use the wrong syscall to remove the object.

Workaround

I found that just adding a sleep 1 before rm -rf causes this to work consistently. Obviously, just sleeping isn't a great solution, and a better option would be to determine when we can expect other processes to have finished modifying the filesystem.

I also found that recursively listing the directory (with ls -laR $TEMP_HOME) also causes reliable test completion. I don't know whether caching behavior could be involved, or whether it's just that the listing takes long enough for other things to complete.