jfrog / jfrog-cli

JFrog CLI is a client that provides a simple interface that automates access to the JFrog products.
https://www.jfrog.com/confluence/display/CLI/JFrog+CLI
Apache License 2.0
533 stars 234 forks source link

Artifactory Download only for specific build has timeout #122

Open peshay opened 6 years ago

peshay commented 6 years ago

I uploaded an artifact with build-information to Artifactory and want to download only the artifacts that belong to that one build: jfrog rt dl --build "Common/171" "rpm-tools-qa/co-Common-*.rpm" In my first test it worked great, but now it doesn't anymore ... I checked it and of course this artifact in this repo exists with that name within that build.

[Info] Searching items to download...
[Debug] Searching Artifactory using AQL query:
 items.find({"repo": "rpm-tools-qa","$or": [{"$and":[{"path": {"$match": "."},"name": {"$match": "co-Common-*.rpm"}}]},{"$and":[{"path": {"$match": "co-Common-*"},"name": {"$match": "*.rpm"}}]}]}).include("name","repo","path","actual_md5","actual_sha1","size","type","property")
[Debug] Artifactory response:  200
[Debug] Searching Artifactory using AQL query:
 items.find({"$and" : [{"artifact.module.build.name": {"$eq": "co-Common"}},{"artifact.module.build.number": {"$eq": "171"}}]}).include("name","repo","path","actual_sha1")
[Debug] Searching Artifactory using AQL query:
 items.find({"$and" :[{"repo": "rpm-tools-qa","$or": [{"$and":[{"path": {"$match": "."},"name": {"$match": "co-Common-*.rpm"}}]},{"$and":[{"path": {"$match": "co-Common-*"},"name": {"$match": "*.rpm"}}]}]},{"@build.name": {"$match" : "co-Common"}}]}).include("name","repo","path","actual_sha1","property")
[Debug] Artifactory response:  200
[Info] Downloaded 0 artifacts.
[Error] Artifactory response: 504 Gateway Time-out
<html><body><h1>504 Gateway Time-out</h1>
The server didn't respond in time.
</body></html>
eyalbe4 commented 6 years ago

@peshay, Did you manage to narrow down this 504 Gateway Time-out to this specific download command? I'm asking because it looks like this error originates from the proxy server in front of Artifactory. Does this happen for commands which take a long time to process by Artifactory? Do you see any hint in Artifactory's request.log?

eyalbe4 commented 6 years ago

@peshay, Did you get a chance to look further into this issue following my questions?

peshay commented 6 years ago

@eyalbe4 sorry for staying so long quite on this, I had a workaround for me that worked, but now I'm facing the issue again :)

In the meantime our artifactory runs in a kubernetes cluster and in order to have a clearer view on the network traffic, so that the ingress controller can't be blamed, I used a SSH tunnel directly to the artifactory container.

So this is what I got now in jfrog-cli debug output:

[Info] Searching items to download...
[Debug] Searching Artifactory using AQL query:
 items.find({"repo": "rpm-tools-dev","$or": [{"$and":[{"path": {"$match": "."},"name": {"$match": "*.rpm"}}]},{"$and":[{"path": {"$match": "*"},"name": {"$match": "*.rpm"}}]}]}).include("name","repo","path","actual_md5","actual_sha1","size","type","property")
[Debug] Artifactory response:  200 OK
[Debug] Searching Artifactory using AQL query:
 items.find({"artifact.module.build.name": "cs Tools :: Common","artifact.module.build.number": "89"}).include("name","repo","path","actual_sha1")
[Debug] Searching Artifactory using AQL query:
 items.find({"$and" :[{"repo": "rpm-tools-dev","$or": [{"$and":[{"path": {"$match": "."},"name": {"$match": "*.rpm"}}]},{"$and":[{"path": {"$match": "*"},"name": {"$match": "*.rpm"}}]}]},{"@build.name": {"$match" : "cs Tools :: Common"}}]}).include("name","repo","path","actual_sha1","property")
[Debug] Artifactory response:  200 OK
[Debug] Artifactory response:  200 OK
[Info] [Thread 2] Downloading rpm-tools-dev/cs-Common-1.6-0.x86_64.rpm
[Debug] [Thread 2]  File already exists locally.
[Debug] Downloaded 1 artifacts.
{
  "status": "success",
  "totals": {
    "success": 1,
    "failure": 0
  }
}

This time, it's a success, but just because it took 9 Minutes overall, if it takes 10 minutes, I get a timeout.

This is what is shown in the requests.log of artifactory

20180919183301|136|REQUEST|0:0:0:0:0:0:0:1|ahu|POST|/api/search/aql|HTTP/1.1|200|258
20180919183512|131336|REQUEST|0:0:0:0:0:0:0:1|ahu|POST|/api/search/aql|HTTP/1.1|200|151
20180919183519|648418|REQUEST|0:0:0:0:0:0:0:1|ahu|POST|/api/search/aql|HTTP/1.1|200|300
20180919183656|675604|REQUEST|0:0:0:0:0:0:0:1|ahu|POST|/api/search/aql|HTTP/1.1|200|300
20180919183725|665999|REQUEST|0:0:0:0:0:0:0:1|ahu|POST|/api/search/aql|HTTP/1.1|200|300
20180919183924|647811|REQUEST|0:0:0:0:0:0:0:1|ahu|POST|/api/search/aql|HTTP/1.1|200|300
20180919184202|541488|REQUEST|0:0:0:0:0:0:0:1|ahu|POST|/api/search/aql|HTTP/1.1|200|300

I also captured the TCP traffic if that would help for further analysis, won't share it here since it has my API key in plain text.

DimaNevelev commented 6 years ago

@peshay, The CLI runs multiple queries in order to determine which artifacts are associated with the required build. From the information you provided, I can see that one of two specific queries cause the timeout, however, I am not sure which one. Can you please determine which one takes more time on your envirenment? items.find({"artifact.module.build.name": "cs Tools :: Common","artifact.module.build.number": "89"}).include("name","repo","path","actual_sha1") or items.find({"$and" :[{"repo": "rpm-tools-dev","$or": [{"$and":[{"path": {"$match": "."},"name": {"$match": "*.rpm"}}]},{"$and":[{"path": {"$match": "*"},"name": {"$match": "*.rpm"}}]}]},{"@build.name": {"$match" : "cs Tools :: Common"}}]}).include("name","repo","path","actual_sha1","property")

You can find the long query by executing each aql query as following: curl -H "Content-Type: text/plain" -vvv -d 'PUT_EACH_QUERY_HERE' -u USERNAME:PASSWORD "http://ARTIFACTORY_URL/artifactory/api/search/aql" >/dev/null 2>>output.txt

peshay commented 6 years ago

Both queries take several minutes, which in my eyes is way too long. I just tested it a few times, the first one took 8 minutes, the second 6 minutes. In another test the first one took 4 minutes, the second one took 6 minutes. Are these query times normal at all? Shouldn't it be more in the range of 10 seconds? I tested it again just now and both ran in the timeout of 10 minutes.

DimaNevelev commented 6 years ago

@peshay, Is your Artifactory configured to work with Derby database by any chance? I'm asking because Derby isn't always optimized in terms of performance. I tested these queries against heavily loaded Artifactory instances and the queries took a few seconds to finish.

peshay commented 6 years ago

@DimaNevelev Yes, we have Derby.