Error fstatat when "Committing stage build-... to cache"

[aleb]

Linux distribution and version

Very recent ArchLinux

Flatpak-builder version

flatpak-builder 1.0.9

Description of the problem / Steps to reproduce

Create a directory with the following manifest.json:

{
    "app-id": "org.pitivi.Pitivi",
    "branch": "master",
    "runtime": "org.gnome.Platform",
    "runtime-version": "3.34",
    "command": "pitivi",
    "finish-args": [
        "--socket=x11",
        "--share=ipc",
        "--socket=pulseaudio",
        "--socket=wayland",
        "--filesystem=xdg-run/dconf",
        "--filesystem=~/.config/dconf:ro",
        "--talk-name=ca.desrt.dconf",
        "--env=DCONF_USER_CONFIG_DIR=.config/dconf",
        "--talk-name=org.freedesktop.Notifications",
        "--filesystem=host",
        "--device=dri"
    ],
    "sdk": "org.gnome.Sdk",
    "copy-icon": true,
    "build-options": {
        "env": {
            "PYTHON": "python3",
            "GST_PLUGIN_SYSTEM_PATH": "/app/lib/gstreamer-1.0/",
            "FREI0R_PATH": "/app/lib/frei0r-1/"
        },
        "strip": false,
        "no-debuginfo": true
    },
    "modules": [
        {
            "name": "opencv",
            "buildsystem": "cmake-ninja",
            "builddir": true,
            "cleanup": [
                "/bin"
            ],
            "sources": [
                {
                    "type": "archive",
                    "url": "https://github.com/opencv/opencv/archive/3.4.8.tar.gz",
                    "sha256": "f0901648a1db3dc3af30e65082665921dbe998673137380450bdd91e8251b567"
                }
            ]
        }
    ]
}

Try to build it:

$ flatpak-builder --force-clean --ccache prefix1 manifest.json --build-only
...
-- Installing: /app/bin/opencv_version
-- Set runtime path of "/app/bin/opencv_version" to "/app/lib"
Committing stage build-opencv to cache
builder_cache_commit 1
builder_cache_commit 2
builder_cache_commit 3
builder_cache_commit 4
builder_cache_commit 5
builder_cache_commit 6
builder_cache_commit 16
builder_cache_commit 17
builder_cache_commit 18
Error: fstatat(.fuse_hidden000002b0000000ee): No such file or directory

[aleb]

I see "Committing stage" in builder_cache_commit in builder-cache.c.

"fstatat(%s)" appears to be in libglnx/glnx-fdio.h and in a few ostreedev/ostree/src/libostree/ files:

src/libostree/ostree-repo-static-delta-core.c - _ostree_repo_static_delta_delete src/libostree/ostree-sysroot-deploy.c - get_kernel_from_tree_usrlib_modules src/libostree/ostree-repo.c - _ostree_repo_has_loose_object

Since builder_cache_commit has a lot of calls to ostree_repo_*, I'd guess it's one of those calling _ostree_repo_has_loose_object.

A search for ".fuse_hidden*" shows it's a file which has been deleted but is still opened.

Any suggestion how to find out what's going on?

[aleb]

I rebuilt the archlinux flatpak-builder package with some additional g_print ("builder_cache_commit 1\n"); statements and now it built.

[aleb]

rm -rf $(find . -name .flatpak-builder)

[aleb]

I keep noticing this issue

[wjt]

Race condition in rofile-fuse?

[aleb]

Can you reproduce the error if you build manifest.json?

[aleb]

I rebuilt locally the ostree package and with the locally built ostree it runs fine. Seems to be an issue related to how ostree is built by archlinux. But no idea why only I see this bug.

[aleb]

I added some debug output to flatpak-builder and to ostree:

• flatpak-builder: https://github.com/aleb/flatpak-builder/commit/9339cb47e21e04644ae81f87440d3b8454d147e2
• ostree: https://github.com/aleb/ostree/commit/772bccb17f6db84a33a5618b1ce6b5efe9568c84

"Unfortunately" the build succeeded, but the previous failure printed this:

CALLING builder_cache_commit from builder_manifest 1
Committing stage build-opencv to cache
builder_cache_commit 1
builder_cache_commit 2
builder_cache_commit 3
builder_cache_commit 4
builder_cache_commit 5
builder_cache_commit 6
ostree_repo_write_directory_to_mtree: 1
ostree_repo_write_dfd_to_mtree: 1
ostree_repo_write_dfd_to_mtree: 2

builder_cache_commit 16
builder_cache_commit 17
builder_cache_commit 18
Error: fstatat(.fuse_hidden000003f300000115): No such file or directory

..meaning this call failed:

  g_print ("ostree_repo_write_dfd_to_mtree: 2\n");
  if (!write_dfd_iter_to_mtree_internal (self, &dfd_iter, mtree, modifier, pathbuilder,
                                         cancellable, error))
    return FALSE;

https://github.com/aleb/ostree/blob/772bccb17f6db84a33a5618b1ce6b5efe9568c84/src/libostree/ostree-repo-commit.c#L4086

The error is returned by write_dfd_iter_to_mtree_internal.. I'll dig in some more next time when it errors.

[aleb]

The chain of calls is:

• builder_cache_commit
• ostree_repo_write_directory_to_mtree
• ostree_repo_write_dfd_to_mtree
• write_dfd_iter_to_mtree_internal
• write_dir_entry_to_mtree_internal
• ...
• write_dfd_iter_to_mtree_internal (again)
• glnx_fstatat:

https://github.com/aleb/ostree/blob/ab566d29b98e2f00fe1bc3f9be43ec81de45aa51/src/libostree/ostree-repo-commit.c#L3988

      if (!glnx_fstatat (src_dfd_iter->fd, dent->d_name, &stbuf, AT_SYMLINK_NOFOLLOW, error)) {
        g_print ("write_dfd_iter_to_mtree_internal: 53\n");
        return FALSE;
      }

[aleb]

These are the calls performed by ostree, read from bottom to top:

write_dfd_iter_to_mtree_internal: returning FALSE because glnx_fstatat failed: dent->d_name=.fuse_hidden000003e400000114
write_dir_entry_to_mtree_internal: returning FALSE because write_dfd_iter_to_mtree_internal failed: path=/files/share/OpenCV/lbpcascades
write_dfd_iter_to_mtree_internal: returning FALSE because write_dir_entry_to_mtree_internal failed: path=/files/share/OpenCV
write_dir_entry_to_mtree_internal: returning FALSE because write_dfd_iter_to_mtree_internal failed: path=/files/share/OpenCV
write_dfd_iter_to_mtree_internal: returning FALSE because write_dir_entry_to_mtree_internal failed: path=/files/share
write_dir_entry_to_mtree_internal: returning FALSE because write_dfd_iter_to_mtree_internal failed: path=/files/share
write_dfd_iter_to_mtree_internal: returning FALSE because write_dir_entry_to_mtree_internal failed: path=/files
write_dir_entry_to_mtree_internal: returning FALSE because write_dfd_iter_to_mtree_internal failed: path=/files
write_dfd_iter_to_mtree_internal: returning FALSE because write_dir_entry_to_mtree_internal failed: path=/
ostree_repo_write_dfd_to_mtree: returning FALSE because write_dfd_iter_to_mtree_internal failed: path=/home/aleb/dev/pitivi/pitivi-prefix
Error: fstatat(.fuse_hidden000003e400000114): No such file or directory

At the deepest level, this fails at:

write_dfd_iter_to_mtree_internal: returning FALSE because glnx_fstatat failed: dent->d_name=.fuse_hidden000003e400000114

(https://github.com/aleb/ostree/blob/3a247540a05590b8d1816d74d14edcadd5429e6e/src/libostree/ostree-repo-commit.c#L3991)

This happens after the while loop iterates through the following items:

write_dfd_iter_to_mtree_internal: dent->d_name=.fuse_hidden000003de00000111
write_dfd_iter_to_mtree_internal: dent->d_name=lbpcascade_silverware.xml
write_dfd_iter_to_mtree_internal: dent->d_name=lbpcascade_frontalcatface.xml
write_dfd_iter_to_mtree_internal: dent->d_name=lbpcascade_profileface.xml
write_dfd_iter_to_mtree_internal: dent->d_name=.fuse_hidden000003e200000113
write_dfd_iter_to_mtree_internal: dent->d_name=lbpcascade_frontalface.xml
write_dfd_iter_to_mtree_internal: dent->d_name=lbpcascade_frontalface_improved.xml
write_dfd_iter_to_mtree_internal: dent->d_name=.fuse_hidden000003e000000112
write_dfd_iter_to_mtree_internal: dent->d_name=.fuse_hidden000003e400000114