conan-io / conan

Conan - The open-source C and C++ package manager
https://conan.io
MIT License
8.23k stars 980 forks source link

[question] Conan cache is walked while doing conandata.yml export? #9173

Closed harsszegi closed 3 years ago

harsszegi commented 3 years ago

Hi,

I am doing a conan create in Docker for a png package and I found out that it "stops for a while" while doing export of conandata.yml. I've done an strace on the python process and it turned out it walks through the Conan cache.

######## conan create 1.6.37-11-8c2e132-dirty@ Exporting package recipe png/1.6.37-11-8c2e132-dirty@cognex/master exports: File 'conandata.yml' found. Exporting it... [...]

This is done:

lstat("/home/cognoid/.conandata/icu/60.2-d45ca1c-63/cognex/master/build/ac768d0a6c8b7aec0443558f797d8419d15b0e2a/icu-src/samples/date", {st_mode=S_IFDIR|0777, st_size=0, ...}) = 0 openat(AT_FDCWD, "/home/cognoid/.conandata/icu/60.2-d45ca1c-63/cognex/master/build/ac768d0a6c8b7aec0443558f797d8419d15b0e2a/icu-src/samples/layout", O_RDONLY|O_NONBLOCK|O_CLOEXEC|O_DIRECTORY) = 3 fstat(3, {st_mode=S_IFDIR|0777, st_size=0, ...}) = 0 getdents(3, / 3 entries /, 32768) = 80 getdents(3, / 0 entries /, 32768) = 0 close(3) = 0 lstat("/home/cognoid/.conandata/icu/60.2-d45ca1c-63/cognex/master/build/ac768d0a6c8b7aec0443558f797d8419d15b0e2a/icu-src/samples/layout", {st_mode=S_IFDIR|0777, st_size=0, ...}) = 0 openat(AT_FDCWD, "/home/cognoid/.conandata/icu/60.2-d45ca1c-63/cognex/master/build/ac768d0a6c8b7aec0443558f797d8419d15b0e2a/icu-src/source", O_RDONLY|O_NONBLOCK|O_CLOEXEC|O_DIRECTORY) = 3 fstat(3, {st_mode=S_IFDIR|0777, st_size=4096, ...}) = 0 getdents(3, / 26 entries /, 32768) = 808 getdents(3, / 0 entries /, 32768) = 0 close(3) = 0 lstat("/home/cognoid/.conandata/icu/60.2-d45ca1c-63/cognex/master/build/ac768d0a6c8b7aec0443558f797d8419d15b0e2a/icu-src/source", {st_mode=S_IFDIR|0777, st_size=4096, ...}) = 0 openat(AT_FDCWD, "/home/cognoid/.conandata/icu/60.2-d45ca1c-63/cognex/master/build/ac768d0a6c8b7aec0443558f797d8419d15b0e2a/icu-src/source/allinone", O_RDONLY|O_NONBLOCK|O_CLOEXEC|O_DIRECTORY) = 3 fstat(3, {st_mode=S_IFDIR|0777, st_size=0, ...}) = 0 getdents(3, / 4 entries /, 32768) = 112 getdents(3, / 0 entries /, 32768) = 0 close(3) = 0 lstat("/home/cognoid/.conandata/icu/60.2-d45ca1c-63/cognex/master/build/ac768d0a6c8b7aec0443558f797d8419d15b0e2a/icu-src/source/allinone", {st_mode=S_IFDIR|0777, st_size=0, ...}) = 0 openat(AT_FDCWD, "/home/cognoid/.conandata/icu/60.2-d45ca1c-63/cognex/master/build/ac768d0a6c8b7aec0443558f797d8419d15b0e2a/icu-src/source/common", O_RDONLY|O_NONBLOCK|O_CLOEXEC|O_DIRECTORY) = 3 fstat(3, {st_mode=S_IFDIR|0777, st_size=65536, ...}) = 0 getdents(3, / 102 entries /, 32768) = 3568 getdents(3, / 102 entries /, 32768) = 3440 getdents(3, / 95 entries /, 32768) = 3208 getdents(3, / 0 entries /, 32768) = 0 close(3) = 0 lstat("/home/cognoid/.conandata/icu/60.2-d45ca1c-63/cognex/master/build/ac768d0a6c8b7aec0443558f797d8419d15b0e2a/icu-src/source/common", {st_mode=S_IFDIR|0777, st_size=65536, ...}) = 0 mmap(NULL, 262144, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f8db0adb000 openat(AT_FDCWD, "/home/cognoid/.conandata/icu/60.2-d45ca1c-63/cognex/master/build/ac768d0a6c8b7aec0443558f797d8419d15b0e2a/icu-src/source/common/unicode", O_RDONLY|O_NONBLOCK|O_CLOEXEC|O_DIRECTORY) = 3 fstat(3, {st_mode=S_IFDIR|0777, st_size=16384, ...}) = 0

Is there any particular reason to scan the complete cache while doing recipe export? Thanks,

memsharded commented 3 years ago

Hi @harsszegi

At conan export Conan might check existing packages in the cache to see if there is any name conflict (upper-lower case conflicts, but this will only check top-level folders to get matching names, not inside packages), and it will check things like binaries for the current package being exported. But shouldn't be doing anything in other packages not being the exported one, this is surprising to me too. I have done a first read to the source code, and I can't find anything that would explain this.

Is that the complete log? It seems only about your cache icu package, or is actually a much longer log, checking all packages in the cache? Can you consistently reproduce it from a blank cache? Is it possible that you have any other process (antivirus or the like) that will fire to scan a folder as soon as changes are detected there?

memsharded commented 3 years ago

Is it possible that you are using scm too? Does this still happen if you don't use it?

harsszegi commented 3 years ago

Nope, it is only part of the log, I have 60ish recipes in the Conan cache already, some of them are small, some of them are huge. Currently the export takes ~10 minutes for me. This is mostly because I am bind mounting my Windows Conan cache into Docker and I am using Docker for Windows with Hyper-V, which is damn slow when accessing Windows shares in Linux guest. What I don't fully understand is why to recurse into build folders and recipe sources and such. Also I am doing --build=missing, no clue whether that affects anything to that regard or not. Have uploaded the zipped log to my own web server: https://harsszegi.com/strace.zip

Please note that this is not the complete log, but only "after a bit" when I could execute the conan command, figure out the python process's pid and strace against it.

nope, it's a dead simple conanfile.py:

import os, os.path
from conans import ConanFile, CMake, tools, errors
from pathlib import Path

class PngConan(ConanFile):
  name = "png" # has to match CMake project() - without the "_recipe"
  exports_sources = "CMakeLists.txt", "lynx.yaml"
  python_requires = "cognex-conanfile-bases/master@cognex/master"
  python_requires_extend = "cognex-conanfile-bases.CognexConanBase"
  build_requires = "cognex-cmake/master@cognex/master"

  def init(self):
    super().init()
    base = self.python_requires["cognex-conanfile-bases"].module.CognexConanBase
    self.options.update(base.options)
    self.default_options.update(base.default_options)

  def source_dir(self):
    return "lpng{}".format(self.simple_version().replace('.',''))

  def configure(self):
    super().configure()
    # KB-H011, KB-H012
    super().configure_c()

  def requirements(self):
    self.requires("zlib/1.2.11-25-6b869fe@cognex/master")

And neither the python_requires base class does any voodoo dark majic, nor the cognex-cmake package, which is just a bundle of .cmake scripts

memsharded commented 3 years ago

What I don't fully understand is why to recurse into build folders and recipe sources and such. Also I am doing --build=missing, no clue whether that affects anything to that regard or not.

No, it shouldn't recurse into the build folders, this is why it is so surprising also for me. I am running some experiments, but I can't find this recursion. The --build=missing is not connected to this, this is not an argument to conan export at all, it should error if you pass it, isn't it erroring? Or you probably use it elsewhere in your code, but not the conan export command?

harsszegi commented 3 years ago

I have absolutely no idea what is going on. This is the output of conan create:

######## conan create 1.6.37-11-8c2e132-dirty@ Exporting package recipe png/1.6.37-11-8c2e132-dirty@cognex/master exports: File 'conandata.yml' found. Exporting it... [.... -> this is the place where the directory walk happens] png/1.6.37-11-8c2e132-dirty@cognex/master exports: Copied 1 '.yml' file: conandata.yml

And after conandata.yml has been copied, everything is just fine (in terms of speed)

harsszegi commented 3 years ago

Couldn't it be the FileCopier doing something silly? (e.g. _filter_files within _copy maybe?)

memsharded commented 3 years ago

conan create 1.6.37-11-8c2e132-dirty@

Well, the conan create really can check many things in the cache, because it expands the dependency graph, computing and checking binaries of dependencies, etc. What happens if you execute only conan export 1.6.37-11-8c2e132-dirty@?

harsszegi commented 3 years ago

Same thing, "File 'conandata.yml' found. Exporting it..." shown, >4 minutes passes, then "Copied 1 '.yml' file: conandata.yml"

memsharded commented 3 years ago

Could you please try to reproduce it without the docker setup? Just in case docker could be related, I still cannot figure out what else to try or to check, I have now followed twice the source code while executing the export flow, without a clue of what could it be.

harsszegi commented 3 years ago

But I can't trace it on Windows outside of Docker :( and it executes (obviously as being on a local filesystem) blazingly fast - compared to the Docker environment. Anyhow will try to compile Conan from source (to add some print()s here and there)

harsszegi commented 3 years ago

Ok, here is the "log", obviously file_copier.py was decorated and export.py was changed like this:

package_output.info("Pre unlink {}".format(origin_folder))
try:
    os.unlink(os.path.join(origin_folder, CONANFILE + 'c'))
except OSError:
    pass
package_output.info("Post unlink {}".format(origin_folder))

package_output.info("Pre FileCopier")
copier = FileCopier([origin_folder], destination_folder)
package_output.info("Post FileCopier")
for pattern in included_exports:
    package_output.info("Copying '{}'...".format(pattern))
    copier(pattern, links=True, excludes=excluded_exports)
package_output.info("Pre copier report")
copier.report(package_output)
package_output.info("Post copier report")

_run_method(conanfile, "export", origin_folder, destination_folder, output)
package_output.info("Post _run_method")

png/1.6.37-11-1a98244-dirty@cognex/master exports: File 'conandata.yml' found. Exporting it... png/1.6.37-11-1a98244-dirty@cognex/master exports: Pre unlink /home/cognoid png/1.6.37-11-1a98244-dirty@cognex/master exports: Post unlink /home/cognoid png/1.6.37-11-1a98244-dirty@cognex/master exports: Pre FileCopier png/1.6.37-11-1a98244-dirty@cognex/master exports: Post FileCopier png/1.6.37-11-1a98244-dirty@cognex/master exports: Copying 'conandata.yml'... _filter_files src /home/cognoid/ pattern conandata.yml root /home/cognoid/ subfolders ['.cache', '.conan', '.conandata', '.git', '.local', 'conan_src', 'python_deps', 'test_package'] root /home/cognoid/.cache subfolders ['pip'] root /home/cognoid/.cache/pip subfolders ['http', 'selfcheck'] root /home/cognoid/.cache/pip/http subfolders ['a', 'b', 'f'] root /home/cognoid/.cache/pip/http/a subfolders ['1'] root /home/cognoid/.cache/pip/http/a/1 subfolders ['9'] root /home/cognoid/.cache/pip/http/a/1/9 subfolders ['5'] root /home/cognoid/.cache/pip/http/a/1/9/5 subfolders ['3'] root /home/cognoid/.cache/pip/http/a/1/9/5/3 subfolders [] root /home/cognoid/.cache/pip/http/b subfolders ['b'] root /home/cognoid/.cache/pip/http/b/b subfolders ['8'] root /home/cognoid/.cache/pip/http/b/b/8 subfolders ['7'] root /home/cognoid/.cache/pip/http/b/b/8/7 subfolders ['6'] root /home/cognoid/.cache/pip/http/b/b/8/7/6 subfolders [] root /home/cognoid/.cache/pip/http/f subfolders ['e'] root /home/cognoid/.cache/pip/http/f/e subfolders ['d'] root /home/cognoid/.cache/pip/http/f/e/d subfolders ['0'] root /home/cognoid/.cache/pip/http/f/e/d/0 subfolders ['e'] root /home/cognoid/.cache/pip/http/f/e/d/0/e subfolders [] root /home/cognoid/.cache/pip/selfcheck subfolders [] root /home/cognoid/.conan subfolders ['dockerfiles', 'hooks', 'lynx-build-targets', 'profiles'] root /home/cognoid/.conan/dockerfiles subfolders ['aarch64-dev1', 'linux64-dev1'] root /home/cognoid/.conan/dockerfiles/aarch64-dev1 subfolders [] root /home/cognoid/.conan/dockerfiles/linux64-dev1 subfolders [] root /home/cognoid/.conan/dockerfiles/vc200-dev0 subfolders [] root /home/cognoid/.conan/hooks subfolders [] root /home/cognoid/.conan/lynx-build-targets subfolders [] root /home/cognoid/.conan/profiles subfolders [] root /home/cognoid/.conandata subfolders ['app1', 'app2', 'asio', 'base64', 'cereal', 'cognex-cmake', 'cognex-conan', 'cognex-conanfile-bases', 'fmt', 'icu', 'jpeg', 'liba', 'libb', 'libc', 'libd', 'lttng-ust', 'openssl', 'png', 'popt', 'pybind11', 'rttr', 'sdl2', 'sigslot', 'spdlog', 'spidermonkey', 'sqlite3', 'sqlite3pp', 'tiff', 'tinyxml2', 'trompeloeil', 'unixodbc', 'urcu', 'uuid', 'yaml-cpp', 'zlib'] root /home/cognoid/.conandata/app1 subfolders ['0.1'] root /home/cognoid/.conandata/app1/0.1 subfolders ['user'] root /home/cognoid/.conandata/app1/0.1/user subfolders ['testing'] root /home/cognoid/.conandata/app1/0.1/user/testing subfolders ['build', 'export', 'export_source', 'package', 'source'] root /home/cognoid/.conandata/app1/0.1/user/testing/build subfolders ['5a44f72db9a39bda919cc01fd3204411df378fb9', '89c22fdf7b9e8fb194dfa67112d645618ca2ed57'] root /home/cognoid/.conandata/app1/0.1/user/testing/build/5a44f72db9a39bda919cc01fd3204411df378fb9 subfolders [] root /home/cognoid/.conandata/app1/0.1/user/testing/build/89c22fdf7b9e8fb194dfa67112d645618ca2ed57 subfolders [] root /home/cognoid/.conandata/app1/0.1/user/testing/export subfolders [] root /home/cognoid/.conandata/app1/0.1/user/testing/export_source subfolders [] root /home/cognoid/.conandata/app1/0.1/user/testing/package subfolders ['5a44f72db9a39bda919cc01fd3204411df378fb9', '89c22fdf7b9e8fb194dfa67112d645618ca2ed57'] root /home/cognoid/.conandata/app1/0.1/user/testing/package/5a44f72db9a39bda919cc01fd3204411df378fb9 subfolders [] root /home/cognoid/.conandata/app1/0.1/user/testing/package/89c22fdf7b9e8fb194dfa67112d645618ca2ed57 subfolders [] root /home/cognoid/.conandata/app1/0.1/user/testing/source subfolders [] root /home/cognoid/.conandata/app2 subfolders ['0.1'] root /home/cognoid/.conandata/app2/0.1 subfolders ['user'] root /home/cognoid/.conandata/app2/0.1/user subfolders ['testing'] root /home/cognoid/.conandata/app2/0.1/user/testing subfolders ['build', 'export', 'export_source', 'package', 'source'] root /home/cognoid/.conandata/app2/0.1/user/testing/build subfolders ['2b54a21f384b01901f126bf69b3e11174695f431', 'bc00cad349c827b96b9835ddd412bca21674aec2'] root /home/cognoid/.conandata/app2/0.1/user/testing/build/2b54a21f384b01901f126bf69b3e11174695f431 subfolders [] root /home/cognoid/.conandata/app2/0.1/user/testing/build/bc00cad349c827b96b9835ddd412bca21674aec2 subfolders [] root /home/cognoid/.conandata/app2/0.1/user/testing/export subfolders [] root /home/cognoid/.conandata/app2/0.1/user/testing/export_source subfolders [] root /home/cognoid/.conandata/app2/0.1/user/testing/package subfolders ['2b54a21f384b01901f126bf69b3e11174695f431', 'bc00cad349c827b96b9835ddd412bca21674aec2'] root /home/cognoid/.conandata/app2/0.1/user/testing/package/2b54a21f384b01901f126bf69b3e11174695f431 subfolders [] root /home/cognoid/.conandata/app2/0.1/user/testing/package/bc00cad349c827b96b9835ddd412bca21674aec2 subfolders [] root /home/cognoid/.conandata/app2/0.1/user/testing/source subfolders []

harsszegi commented 3 years ago

Just a question. If the pattern is not a regexp (I mean exact filename), why filtering is needed?

memsharded commented 3 years ago

Thanks for the debugging, I think this is good info.

It seems the reason that it is walking the cache, is because the cache is somehow located below the package that is being exported? What is your folder structure and layout? The current folder, the folder containing the conanfile.py, the folder containing the cache, etc.

Just a question. If the pattern is not a regexp (I mean exact filename), why filtering is needed?

Because matching is not regex based, it is fnmatch based, it is not possible to differentiate an exact match from a filename match.

harsszegi commented 3 years ago

I am closing this. Our setup was “flawed” in terms that we were bind mounting the recipe repository as $HOME and surely we also bind mounted .conan into this as well, so no surprise Conan walked through the entire cache. We have changed our logic to map the recipe repo into a separate subdirectory inside $HOME, so .conan now lives outside of the mounted recipe repo. Thanks @memsharded for the assistance! t.

memsharded commented 3 years ago

I am closing this. Our setup was “flawed” in terms that we were bind mounting the recipe repository as $HOME and surely we also bind mounted .conan into this as well, so no surprise Conan walked through the entire cache.

Great we finally got to the issue!

Thanks @memsharded for the assistance!

Happy to help! 😄 Thanks for the feedback too, let us know if you have any other issue!