slow performance with lots of Requires: statements #229

New Issue

ariadne · 2021-07-27T15:29:21Z

devjgm commented

2021-07-27 15:29:21 +00:00

(Migrated from github.com)

When upgrading my (C++) project to gRPC 1.39.0 (the latest), I discovered that Fedora's pkgconf seems to be slow when .pc files have many Requires: clauses. The issue from my project is https://github.com/googleapis/google-cloud-cpp/issues/7052 and it has some additional context. We worked around this problem by installing and using https://pkgconfig.freedesktop.org/releases/pkg-config-0.29.2.tar.gz instead.

It is possible that we're doing something wrong, in which case I'd be happy to learn what it is so we can fix it. Otherwise, I'm reporting this issue in case it can be fixed in a future version of pkgconf/fedora.

Steps to reproduce

Download the pkgconfig-files.tar.gz tarball, which contains all the *.pc files from a fully installed copy of google-cloud-cpp, protobuf, grpc, abseil, openssl, etc. This tarball does NOT contain the compiled artifacts -- only the .pc files. This is just so that we can use pkg-config in a docker container to reproduce the problem.
Start a new docker container w/ the above tarball mounted so that the files can be extracted into /tmp in the image.

$ docker run --rm -it --volume=$PWD/pkgconfig-files.tar.gz:/tarball fedora:34 bash

Within the running container, extract the tarball into /tmp, which will put all the .pc files in a single directory

[root@b1cac6cb716c /]# tar -C /tmp -zxvf /tarball
...
[root@b1cac6cb716c /]# export PKG_CONFIG_PATH=/tmp/pkgconfig-files

Install pkg-config

[root@b1cac6cb716c /]# dnf install -y pkgconfig

See how slow pkg-config is for certain packages that contain a lot of Requires: statements.

[root@b1cac6cb716c /]# time pkg-config google_cloud_cpp_grpc_utils --libs-only-l --static
...
real    0m3.184s
user    0m3.155s
sys     0m0.028s

The above is over 3 seconds. Invoked repeatedly in our actual CI builds this adds up to over an hour of time spent in pkg-config. When we switched our builds to https://pkgconfig.freedesktop.org/releases/pkg-config-0.29.2.tar.gz (https://github.com/googleapis/google-cloud-cpp/pull/7061), each invocation completes in a small fraction of a second.

Additional info

I don't know about the internals of pkg-config, so I don't really know what it's doing or supposed to do, but I'll say that the --debug flag produces some interesting output.

[root@b1cac6cb716c /]# pkg-config google_cloud_cpp_grpc_utils --debug 2>&1 | grep -Po '\[pkgconf.+\]' | sort | uniq -c | sort -n
...
     69 [pkgconf_fragment_parse]: post-subst: [-I${includedir} -DNOMINMAX] -> [-I/usr/local/include -DNOMINMAX]
     90 [pkgconf_cache_add]
     90 [pkgconf_cache_remove]
    180 [pkgconf_pkg_try_specific_path]
    309 [pkgconf_fragment_add]
    393 [pkgconf_cache_lookup]
    452 [pkgconf_tuple_add]
    696 [pkgconf_pkg_find]
 458241 [pkgconf_pkg_ref]
 458241 [pkgconf_pkg_unref]
 915123 [pkgconf_pkg_verify_dependency]
 915518 [pkgconf_pkg_traverse]

When upgrading my (C++) project to gRPC 1.39.0 (the latest), I discovered that Fedora's `pkgconf` seems to be slow when `.pc` files have many `Requires:` clauses. The issue from my project is https://github.com/googleapis/google-cloud-cpp/issues/7052 and it has some additional context. We worked around this problem by installing and using https://pkgconfig.freedesktop.org/releases/pkg-config-0.29.2.tar.gz instead. It is possible that we're doing something wrong, in which case I'd be happy to learn what it is so we can fix it. Otherwise, I'm reporting this issue in case it can be fixed in a future version of pkgconf/fedora. ## Steps to reproduce 1. Download the [pkgconfig-files.tar.gz](https://github.com/pkgconf/pkgconf/files/6886662/pkgconfig-files.tar.gz) tarball, which contains all the `*.pc` files from a fully installed copy of `google-cloud-cpp`, `protobuf`, `grpc`, `abseil`, `openssl`, etc. This tarball does NOT contain the compiled artifacts -- only the .pc files. This is just so that we can use `pkg-config` in a docker container to reproduce the problem. 2. Start a new docker container w/ the above tarball mounted so that the files can be extracted into `/tmp` in the image. ```console $ docker run --rm -it --volume=$PWD/pkgconfig-files.tar.gz:/tarball fedora:34 bash ``` 3. Within the running container, extract the tarball into `/tmp`, which will put all the `.pc` files in a single directory ```console [root@b1cac6cb716c /]# tar -C /tmp -zxvf /tarball ... [root@b1cac6cb716c /]# export PKG_CONFIG_PATH=/tmp/pkgconfig-files ``` 4. Install `pkg-config` ```console [root@b1cac6cb716c /]# dnf install -y pkgconfig ``` 5. See how slow `pkg-config` is for certain packages that contain a lot of `Requires:` statements. ```console [root@b1cac6cb716c /]# time pkg-config google_cloud_cpp_grpc_utils --libs-only-l --static ... real 0m3.184s user 0m3.155s sys 0m0.028s ``` The above is over 3 seconds. Invoked repeatedly in our actual CI builds this adds up to over an hour of time spent in `pkg-config`. When we switched our builds to https://pkgconfig.freedesktop.org/releases/pkg-config-0.29.2.tar.gz (https://github.com/googleapis/google-cloud-cpp/pull/7061), each invocation completes in a small fraction of a second. ## Additional info I don't know about the internals of pkg-config, so I don't really know what it's doing or supposed to do, but I'll say that the `--debug` flag produces some interesting output. ```console [root@b1cac6cb716c /]# pkg-config google_cloud_cpp_grpc_utils --debug 2>&1 | grep -Po '\[pkgconf.+\]' | sort | uniq -c | sort -n ... 69 [pkgconf_fragment_parse]: post-subst: [-I${includedir} -DNOMINMAX] -> [-I/usr/local/include -DNOMINMAX] 90 [pkgconf_cache_add] 90 [pkgconf_cache_remove] 180 [pkgconf_pkg_try_specific_path] 309 [pkgconf_fragment_add] 393 [pkgconf_cache_lookup] 452 [pkgconf_tuple_add] 696 [pkgconf_pkg_find] 458241 [pkgconf_pkg_ref] 458241 [pkgconf_pkg_unref] 915123 [pkgconf_pkg_verify_dependency] 915518 [pkgconf_pkg_traverse] ```

ariadne commented

2021-10-06 16:21:36 +00:00

Hi, sorry, I have not noticed this issue until now. For some reason, GitHub does not reliably send bug mail to me for pkgconf anymore.

The pkgconf_pkg_ref/pkgconf_pkg_unref being so high is quite strange.

Hi, sorry, I have not noticed this issue until now. For some reason, GitHub does not reliably send bug mail to me for pkgconf anymore. The `pkgconf_pkg_ref/pkgconf_pkg_unref` being so high is quite strange.

ariadne commented

2021-10-06 16:31:07 +00:00

The issue is that the dependency solver is being invoked thousands of times (e.g. for each subgraph). A probable solution would be to track dependency nodes that are already part of a proposed solution and reusing them for future resolutions.

ariadne commented

2021-10-06 16:33:10 +00:00

The solver, incidentally, is solving for absl_config frequently. Likely that is the deepest point in the graph. I tried to render it with GraphViz but it crashed, haha

The solver, incidentally, is solving for `absl_config` frequently. Likely that is the deepest point in the graph. I tried to render it with GraphViz but it crashed, haha

Sign in to join this conversation.