Conan: Strange behavior of Artifactory remote repos

[db4]

Trying to find an interim solution for #5175 I set up remote Artifactory repos for conan-center (https://conan.bintray.com) and bincrafters (https://api.bintray.com/conan/bincrafters/public-conan) conan repos and used them for CI jobs. I expected Artifactory to get packages from its local cache when they are available and don't waste precious time requesting the remote for anything, but Artifactory logs show quite different behavior. Why?

...
2019-06-25 10:57:52,284 [http-nio-8081-exec-4] [INFO ] (o.a.r.HttpRepo      :432) - bincrafters downloading https://api.bintray.com/conan/bincrafters/public-conan/v2/conans/boost_iterator/1.66.0/bincrafters/stable/revisions/0/packages/5ab84d6acfe1f23c4fae0ab88f26e3a396351ac9/revisions 192 bytes 
2019-06-25 10:57:52,288 [http-nio-8081-exec-4] [INFO ] (o.a.r.HttpRepo      :445) - bincrafters downloaded  https://api.bintray.com/conan/bincrafters/public-conan/v2/conans/boost_iterator/1.66.0/bincrafters/stable/revisions/0/packages/5ab84d6acfe1f23c4fae0ab88f26e3a396351ac9/revisions 192 bytes at 62.18 KB/sec
2019-06-25 10:57:56,774 [http-nio-8081-exec-4] [INFO ] (o.a.r.HttpRepo      :432) - conan-center downloading https://conan.bintray.com/v2/conans/boost_level5group/1.66.0/bincrafters/stable/revisions 98 bytes 
2019-06-25 10:57:56,778 [http-nio-8081-exec-4] [INFO ] (o.a.r.HttpRepo      :445) - conan-center downloaded  https://conan.bintray.com/v2/conans/boost_level5group/1.66.0/bincrafters/stable/revisions 98 bytes at 33.21 KB/sec
2019-06-25 10:57:56,973 [http-nio-8081-exec-4] [ERROR] (o.a.a.c.r.ConanV2RemoteRepoHandler:261) - Unable to fetch latest revision from 'https://conan.bintray.com/v2/conans/boost_level5group/1.66.0/bincrafters/stable/latest': HTTP/1.1 404 Not Found
2019-06-25 10:57:58,405 [http-nio-8081-exec-3] [INFO ] (o.a.r.HttpRepo      :432) - bincrafters downloading https://api.bintray.com/conan/bincrafters/public-conan/v2/conans/boost_mpl/1.66.0/bincrafters/stable/revisions/0/packages/5ab84d6acfe1f23c4fae0ab88f26e3a396351ac9/revisions 187 bytes 
2019-06-25 10:57:58,421 [http-nio-8081-exec-3] [INFO ] (o.a.r.HttpRepo      :445) - bincrafters downloaded  https://api.bintray.com/conan/bincrafters/public-conan/v2/conans/boost_mpl/1.66.0/bincrafters/stable/revisions/0/packages/5ab84d6acfe1f23c4fae0ab88f26e3a396351ac9/revisions 187 bytes at 11.66 KB/sec
2019-06-25 10:58:00,790 [http-nio-8081-exec-8] [INFO ] (o.a.r.HttpRepo      :432) - bincrafters downloading https://api.bintray.com/conan/bincrafters/public-conan/v2/conans/boost_level5group/1.66.0/bincrafters/stable/revisions 152 bytes 
2019-06-25 10:58:00,812 [http-nio-8081-exec-8] [INFO ] (o.a.r.HttpRepo      :445) - bincrafters downloaded  https://api.bintray.com/conan/bincrafters/public-conan/v2/conans/boost_level5group/1.66.0/bincrafters/stable/revisions 152 bytes at 9.33 KB/sec
2019-06-25 10:58:04,681 [http-nio-8081-exec-5] [INFO ] (o.a.r.HttpRepo      :432) - bincrafters downloading https://api.bintray.com/conan/bincrafters/public-conan/v2/conans/boost_optional/1.66.0/bincrafters/stable/revisions/0/packages/5ab84d6acfe1f23c4fae0ab88f26e3a396351ac9/revisions 192 bytes 
2019-06-25 10:58:04,684 [http-nio-8081-exec-5] [INFO ] (o.a.r.HttpRepo      :445) - bincrafters downloaded  https://api.bintray.com/conan/bincrafters/public-conan/v2/conans/boost_optional/1.66.0/bincrafters/stable/revisions/0/packages/5ab84d6acfe1f23c4fae0ab88f26e3a396351ac9/revisions 192 bytes at 72.42 KB/sec
2019-06-25 10:58:05,600 [http-nio-8081-exec-4] [INFO ] (o.a.r.HttpRepo      :432) - conan-center downloading https://conan.bintray.com/v2/conans/boost_integer/1.66.0/bincrafters/stable/revisions 94 bytes 
2019-06-25 10:58:05,604 [http-nio-8081-exec-4] [INFO ] (o.a.r.HttpRepo      :445) - conan-center downloaded  https://conan.bintray.com/v2/conans/boost_integer/1.66.0/bincrafters/stable/revisions 94 bytes at 30.85 KB/sec
2019-06-25 10:58:05,796 [http-nio-8081-exec-4] [ERROR] (o.a.a.c.r.ConanV2RemoteRepoHandler:261) - Unable to fetch latest revision from 'https://conan.bintray.com/v2/conans/boost_integer/1.66.0/bincrafters/stable/latest': HTTP/1.1 404 Not Found
2019-06-25 10:58:10,205 [http-nio-8081-exec-1] [INFO ] (o.a.r.HttpRepo      :432) - bincrafters downloading https://api.bintray.com/conan/bincrafters/public-conan/v2/conans/boost_integer/1.66.0/bincrafters/stable/revisions 148 bytes 
2019-06-25 10:58:10,208 [http-nio-8081-exec-1] [INFO ] (o.a.r.HttpRepo      :445) - bincrafters downloaded  https://api.bintray.com/conan/bincrafters/public-conan/v2/conans/boost_integer/1.66.0/bincrafters/stable/revisions 148 bytes at 53.81 KB/sec
...

[lasote]

Thanks for the info, I'm asking Artifactory support for help with this.

[memsharded]

JIRA issue: https://www.jfrog.com/jira/browse/RTFACT-19475

@db4 it would be useful if you could add the information of which Artifactory versions, and a complete trace (showing that a second attempt to download will re-download from the proxied repo, that trace could be like the first time those packages are hit). A couple of lines how to reproduce with the conan client (including version) could also be good. Thanks!

[db4]

@memsharded

it would be useful if you could add the information of which Artifactory versions

Artifactory 6.10.4 CE for C/C++

and a complete trace (showing that a second attempt to download will re-download from the proxied repo

Well, it's the complete trace. There are more packages but for all of them, Artifactory does the same. For any package in the local cache, it requests revisions file from its remote repo. bintray.com is quite slow nowadays and it takes several seconds per package (that turns into many minutes for bincrafters' modular boost)

A couple of lines how to reproduce with the conan client (including version) could also be good. Thanks!

I use the latest conan client (1.16.1)/conan package tools 0.28.1 with Gitlab CI. But I believe conan install boost_test/1.66.0@bincrafters/stable will be enough to reproduce the issue.

[lasote]

Have you checked the "store artifacts locally" on the remote repository? The team is not able to reproduce the issue. If it is found locally it shouldn't go remotely.

[db4]

Have you checked the "store artifacts locally" on the remote repository?

yes

If it is found locally it shouldn't go remotely

Even to find revisions available on the remote? The problem is not artifact downloading but discovering remote revisions for cached artifacts. It initiates a network connection (see the log above) and introduces significant delay.

[MohamadJfrog]

Hello,
I reproduce the same behavior on my end, it seems that you have one remote repository to "https://conan.bintray.com", however, the "boost_test/1.66.0@bincrafters/stable" is found in the remote: "https://api.bintray.com/conan/bincrafters/public-conan".
In order to resolve this issue, you need to add another Conan remote repository in Artifactory to "https://api.bintray.com/conan/bincrafters/public-conan" and add it like the following:
$ conan remote add <REMOTE> http://<ARTIAFCTORY_URL>/artifactory/api/conan/<REPOSITORY_KEY>

The client will search the recipe in the first remote since it is not found he will search in the second remote and found it.

On my end, I successfully install "boost_test/1.66.0@bincrafters/stable" after adding the above remote and this flag " --build "boost_*" ", i.e.:
$ conan install boost_test/1.66.0@bincrafters/stable --build "boost_*"

Hope this helps.

[db4]

@MohamadJfrog

it seems that you have one remote repository to "https://conan.bintray.com"

See my first message. Of course, I've created two Artifactory remote repos (for conan-center and bincrafters)

[MohamadJfrog]

I would like to reproduce this behavior on my end in order to debug this issue, to do that, I need the build a similar setup to you, for this, I need the config descriptor file located in {ARTIFACTORY_HOME}/etc/artifactory.config.latest.xml, and the output of the command:
$ conan remote list

Waiting forward to your reply.

[db4]

@MohamadJfrog

I need the config descriptor file located in {ARTIFACTORY_HOME}/etc/artifactory.config.latest.xml

Do you need the full file? If yes, please let me know how to send it privately. remoteRepositories part follows:

    <remoteRepositories>
        <remoteRepository>
            <key>bincrafters</key>
            <type>conan</type>
            <includesPattern>**/*</includesPattern>
            <repoLayoutRef>conan-default</repoLayoutRef>
            <dockerApiVersion>V2</dockerApiVersion>
            <forceNugetAuthentication>false</forceNugetAuthentication>
            <blackedOut>false</blackedOut>
            <handleReleases>true</handleReleases>
            <handleSnapshots>true</handleSnapshots>
            <maxUniqueSnapshots>0</maxUniqueSnapshots>
            <maxUniqueTags>0</maxUniqueTags>
            <suppressPomConsistencyChecks>true</suppressPomConsistencyChecks>
            <propertySets/>
            <archiveBrowsingEnabled>false</archiveBrowsingEnabled>
            <url>https://api.bintray.com/conan/bincrafters/public-conan</url>
            <offline>false</offline>
            <hardFail>false</hardFail>
            <storeArtifactsLocally>true</storeArtifactsLocally>
            <fetchJarsEagerly>false</fetchJarsEagerly>
            <fetchSourcesEagerly>false</fetchSourcesEagerly>
            <retrievalCachePeriodSecs>600</retrievalCachePeriodSecs>
            <assumedOfflinePeriodSecs>300</assumedOfflinePeriodSecs>
            <missedRetrievalCachePeriodSecs>1800</missedRetrievalCachePeriodSecs>
            <remoteRepoChecksumPolicyType>generate-if-absent</remoteRepoChecksumPolicyType>
            <unusedArtifactsCleanupPeriodHours>0</unusedArtifactsCleanupPeriodHours>
            <shareConfiguration>false</shareConfiguration>
            <synchronizeProperties>false</synchronizeProperties>
            <listRemoteFolderItems>true</listRemoteFolderItems>
            <rejectInvalidJars>false</rejectInvalidJars>
            <contentSynchronisation>
                <enabled>false</enabled>
                <statistics>
                    <enabled>false</enabled>
                </statistics>
                <properties>
                    <enabled>false</enabled>
                </properties>
                <source>
                    <originAbsenceDetection>false</originAbsenceDetection>
                </source>
            </contentSynchronisation>
            <blockMismatchingMimeTypes>true</blockMismatchingMimeTypes>
            <mismatchingMimeTypesOverrideList></mismatchingMimeTypesOverrideList>
            <bypassHeadRequests>false</bypassHeadRequests>
            <allowAnyHostAuth>false</allowAnyHostAuth>
            <socketTimeoutMillis>15000</socketTimeoutMillis>
            <enableCookieManagement>false</enableCookieManagement>
            <enableTokenAuthentication>false</enableTokenAuthentication>
            <propagateQueryParams>false</propagateQueryParams>
        </remoteRepository>
        <remoteRepository>
            <key>conan-center</key>
            <type>conan</type>
            <includesPattern>**/*</includesPattern>
            <repoLayoutRef>conan-default</repoLayoutRef>
            <dockerApiVersion>V2</dockerApiVersion>
            <forceNugetAuthentication>false</forceNugetAuthentication>
            <blackedOut>false</blackedOut>
            <handleReleases>true</handleReleases>
            <handleSnapshots>true</handleSnapshots>
            <maxUniqueSnapshots>0</maxUniqueSnapshots>
            <maxUniqueTags>0</maxUniqueTags>
            <suppressPomConsistencyChecks>true</suppressPomConsistencyChecks>
            <propertySets/>
            <archiveBrowsingEnabled>false</archiveBrowsingEnabled>
            <url>https://conan.bintray.com</url>
            <offline>false</offline>
            <hardFail>false</hardFail>
            <storeArtifactsLocally>true</storeArtifactsLocally>
            <fetchJarsEagerly>false</fetchJarsEagerly>
            <fetchSourcesEagerly>false</fetchSourcesEagerly>
            <retrievalCachePeriodSecs>600</retrievalCachePeriodSecs>
            <assumedOfflinePeriodSecs>300</assumedOfflinePeriodSecs>
            <missedRetrievalCachePeriodSecs>1800</missedRetrievalCachePeriodSecs>
            <remoteRepoChecksumPolicyType>generate-if-absent</remoteRepoChecksumPolicyType>
            <unusedArtifactsCleanupPeriodHours>0</unusedArtifactsCleanupPeriodHours>
            <shareConfiguration>false</shareConfiguration>
            <synchronizeProperties>false</synchronizeProperties>
            <listRemoteFolderItems>true</listRemoteFolderItems>
            <rejectInvalidJars>false</rejectInvalidJars>
            <contentSynchronisation>
                <enabled>false</enabled>
                <statistics>
                    <enabled>false</enabled>
                </statistics>
                <properties>
                    <enabled>false</enabled>
                </properties>
                <source>
                    <originAbsenceDetection>false</originAbsenceDetection>
                </source>
            </contentSynchronisation>
            <blockMismatchingMimeTypes>true</blockMismatchingMimeTypes>
            <mismatchingMimeTypesOverrideList></mismatchingMimeTypesOverrideList>
            <bypassHeadRequests>false</bypassHeadRequests>
            <allowAnyHostAuth>false</allowAnyHostAuth>
            <socketTimeoutMillis>15000</socketTimeoutMillis>
            <enableCookieManagement>false</enableCookieManagement>
            <enableTokenAuthentication>false</enableTokenAuthentication>
            <propagateQueryParams>false</propagateQueryParams>
        </remoteRepository>
    </remoteRepositories>

output of the command:
$ conan remote list

conan-center: http://artifactory/artifactory/api/conan/conan-center [Verify SSL: True]
remote0: http://artifactory/artifactory/api/conan/bincrafters [Verify SSL: True]
conan-local: http://artifactory/artifactory/api/conan/conan-local [Verify SSL: True]
bincrafters: https://api.bintray.com/conan/bincrafters/public-conan [Verify SSL: True]
dbely: https://api.bintray.com/conan/dbely/conan [Verify SSL: True]

Indeed, I have bincrafters repo included twice, an Artifactory-cached repo (remote0) and a direct reference (bincrafters). This was not intentional but the cached repo goes first and should be searched first, no?

[memsharded]

I think it would be great if we could reduce the scope of this issue and simplify it.

First step:
Is it possible to reproduce it with the conan client pointing to exclusively 1 remote Artifactory repo that proxies conan-center? I think that having multiple repos in the client should be irrelevant if the issue is that Artifactory is hitting the proxied conan-center instead of returning cached artifacts.

Then, a single conan install is not a complete reproducible example. At least 2 are necessary, the first one will miss the cache and hit conan-center, the second one should return the cached artifacts.

Thanks for the feedback!

[jgsogo]

This is not an issue, it is the expected behavior. In the log from the first message:

2019-06-25 10:57:52,284 [http-nio-8081-exec-4] [INFO ] (o.a.r.HttpRepo      :432) - bincrafters downloading https://api.bintray.com/conan/bincrafters/public-conan/v2/conans/boost_iterator/1.66.0/bincrafters/stable/revisions/0/packages/5ab84d6acfe1f23c4fae0ab88f26e3a396351ac9/revisions 192 bytes 
2019-06-25 10:57:52,288 [http-nio-8081-exec-4] [INFO ] (o.a.r.HttpRepo      :445) - bincrafters downloaded  https://api.bintray.com/conan/bincrafters/public-conan/v2/conans/boost_iterator/1.66.0/bincrafters/stable/revisions/0/packages/5ab84d6acfe1f23c4fae0ab88f26e3a396351ac9/revisions 192 bytes at 62.18 KB/sec

all the requests are looking for the list of _revisions_ (https://...../revisions) to check which one is the last revision available in the proxy repository. Once the revision is resolved, if the package is already available in the remote repo (in the Artifactory cache), the files are retrieved from the remote in Artifactory and not from the proxy repo.

We can check this behavior if we compare it with the logs from the first time we get a package, it shows more calls to the proxy downloading files like conanfile.py, conan_package.tgz,... for the matching recipe revision. Each time we install the package from a remote, it will check for new revisions (so Artifactory will hit the proxy repo), and those are the logs we see.

How to avoid this extra call:

1. Configuring the repository as _offlline_
2. If you explicitly install the recipe revision that is already in Artifactory, no call to the proxy is performed (no need to look for more revisions): conan install boost_test/1.66.0@bincrafters/stable#0 (note the final #0) should not hit the proxy if the revision #0 is the one in the cache.

Please, let me know if you any doubt.

[datalogics-kam]

should not hit the proxy if the revision #0 is the one in the cache.

Tried that.

It only works for direct dependencies. For transitive dependencies, of which there are dozens for modular Boost, it's still calling through to Bincrafters bintray, at a cost of 6-7 seconds per failed retrieval of /latest. For a project that has 69 of these packages, finding the packages, and then the graph calculations, takes an enormous amount of time still.

[jgsogo]

The problem with transitive dependencies is that the revision is not indicated for the transitive dependencies (it isn't for modular boost, indeed), so those transitive dependencies are trying to resolve the latest revision. This is a huge issue, indeed, and to improve it we would need to touch many different products: client, servers,... :/ There are some ideas in the backlog that may alleviate this pain: using a lockfile, once the revision for all the dependencies is set, will help with this, but major improvement should probably come from the server side.

[datalogics-kam]

Sadly, lockfiles are a solution that creates a whole nest of problems, since I'd have to somehow ship a combinatorial explosion of lockfiles to all my teams (lost of projects on lots of platforms with lots of configurations), and all the lockfiles would be invalid once one of our _own_ dependencies changed.

Are there some specific Jira cases I could subscribe to that would at least let me know the progress on these improvements?

[jgsogo]

I'm not sure if the issue reported in #5432 has the same origin or solution, but it is also about performance related to Artifactory.

About the lockfiles and how to handle them within a company, probably @lasote can give you some advice about how to use them (ping him next week), and we would be pleased to know any feedback about them you may have. It is a feature we want to improve and push forward because we think it is very valuable for our users. This is not the issue to talk about _lockfiles_, better not to mix topics, but feel free to open a new one or you can reach us on Slack too. Thanks!