Performance issue: Extremely slow, unpredictable cloning when using HTTPS with GitHub

nrdxp commented 1 month ago

Issue Description

When attempting to use a local josh-proxy instance targeting GitHub via HTTPS, I'm experiencing extremely slow performance during the cloning process. The time to complete a clone operation ranges from a few seconds to over 10 minutes, which seems to defeat josh's purpose of being "blazingly fast".

Observed Behavior

The git clone command appears to hang indefinitely.
Josh logs indicate there is no authentication information present in the request.
After a very long wait (sometimes up to 10 minutes), the repository is eventually cloned.

Attempted Solutions

Tried multiple ways to pass authentication information, including container invocation and client CLI side.
Added the --required-auth flag.
Tested with an empty git config to rule out local configuration issues.

Potential Cause

The slow performance might be due to GitHub rate limiting caused by missing authentication. The logs suggest that authentication information is not being passed through correctly.

Questions

Is there a proper way to pass GitHub authentication through josh that I'm missing?
Could this be related to the size of the repository being cloned (e.g., nixpkgs is exceptionally large)?
Are there any known issues with josh's handling of HTTPS connections to GitHub?

Additional Information

I'm using a git credential helper that works correctly when not using josh.
The "getting started" guide explicitly uses https://github.com as an example, which led me to believe this should work out of the box.

Any insights or suggestions for further debugging would be greatly appreciated.

christian-schilling commented 3 weeks ago

Ni @nrdxp, For JOSH_REMOTE you should just set https://github.com without any credentials. Then when connecting with a git client you need to provide credentials the same way as you would when connecting to github directly. That is, you need to create a token first.

nrdxp commented 3 weeks ago

Right I just didn't know if anything was missing, because as I reported, it doesn't prompt me for credentials, it just hangs indefinitely. At first I thought it might be something in my git config so I tried with an empty one and same result, perhaps its a genuine bug then?

I know github had some issues last week too, so I will try again sometime today and see if perhaps it works better.

nrdxp commented 3 weeks ago

It seems to be genuinely stuck in a loop, so perhaps I should retitle this issue as a bug:

2024-08-20T17:33:18.676167Z DEBUG handle_http_request:call_service: josh_proxy: static_path "/nixos/nixpkgs.git:/lib.git/info/refs" url.path="/nixos/nixpkgs.git:/lib.git/info/refs" http.request.method="GET" req_auth=(Handle { value: None }, Request { method: GET, uri: /nixos/nixpkgs.git:/lib.git/info/refs?service=git-upload-pack, version: HTTP/1.1, headers: {"host": "localhost:8000", "user-agent": "git/2.45.2", "accept": "*/*", "accept-encoding": "deflate, gzip, br, zstd", "accept-language": "en-US, *;q=0.9", "pragma": "no-cache", "git-protocol": "version=2"}, body: Body(Empty) })
2024-08-20T17:33:18.679129Z TRACE handle_http_request:call_service:check_http_auth: josh_proxy::auth: Falling back to default auth: JoshError("no auth found") handle=Handle { value: None } url.path="/nixos/nixpkgs.git:/lib.git/info/refs" http.request.method="GET" req_auth=(Handle { value: None }, Request { method: GET, uri: /nixos/nixpkgs.git:/lib.git/info/refs?service=git-upload-pack, version: HTTP/1.1, headers: {"host": "localhost:8000", "user-agent": "git/2.45.2", "accept": "*/*", "accept-encoding": "deflate, gzip, br, zstd", "accept-language": "en-US, *;q=0.9", "pragma": "no-cache", "git-protocol": "version=2"}, body: Body(Empty) }) url="https://github.com/nixos/nixpkgs.git" auth=Handle { value: None } required=false
2024-08-20T17:33:18.991164Z  INFO handle_http_request:call_service:check_http_auth: josh_proxy::auth: check_http_auth: response http.response.status_code=200 url.path="/nixos/nixpkgs.git:/lib.git/info/refs" http.request.method="GET" req_auth=(Handle { value: None }, Request { method: GET, uri: /nixos/nixpkgs.git:/lib.git/info/refs?service=git-upload-pack, version: HTTP/1.1, headers: {"host": "localhost:8000", "user-agent": "git/2.45.2", "accept": "*/*", "accept-encoding": "deflate, gzip, br, zstd", "accept-language": "en-US, *;q=0.9", "pragma": "no-cache", "git-protocol": "version=2"}, body: Body(Empty) }) url="https://github.com/nixos/nixpkgs.git" auth=Handle { value: None } required=false
2024-08-20T17:33:18.991303Z  INFO handle_http_request:call_service:fetch_upstream:fetch_refs_from_url: josh_proxy: fetch_refs_from_url ["git", "fetch", "--prune", "--no-tags", "https://github.com/nixos/nixpkgs.git", "+HEAD*:refs/josh/upstream/nixos%2Fnixpkgs.git/HEAD*", "+refs/josh/*:refs/josh/upstream/nixos%2Fnixpkgs.git/refs/josh/*", "+refs/heads/*:refs/josh/upstream/nixos%2Fnixpkgs.git/refs/heads/*", "+refs/tags/*:refs/josh/upstream/nixos%2Fnixpkgs.git/refs/tags/*"] "/data/git/mirror" "" url.path="/nixos/nixpkgs.git:/lib.git/info/refs" http.request.method="GET" req_auth=(Handle { value: None }, Request { method: GET, uri: /nixos/nixpkgs.git:/lib.git/info/refs?service=git-upload-pack, version: HTTP/1.1, headers: {"host": "localhost:8000", "user-agent": "git/2.45.2", "accept": "*/*", "accept-encoding": "deflate, gzip, br, zstd", "accept-language": "en-US, *;q=0.9", "pragma": "no-cache", "git-protocol": "version=2"}, body: Body(Empty) }) upstream_repo="/nixos/nixpkgs.git" remote_auth=Http { auth: Handle { value: None } } remote_url="https://github.com/nixos/nixpkgs.git" head_ref=Some("HEAD") head_ref_resolved=None force=false
2024-08-20T17:33:18.991320Z TRACE handle_http_request:call_service:fetch_upstream:fetch_refs_from_url: josh_proxy::auth: Falling back to default auth: JoshError("no auth found") handle=Handle { value: None } url.path="/nixos/nixpkgs.git:/lib.git/info/refs" http.request.method="GET" req_auth=(Handle { value: None }, Request { method: GET, uri: /nixos/nixpkgs.git:/lib.git/info/refs?service=git-upload-pack, version: HTTP/1.1, headers: {"host": "localhost:8000", "user-agent": "git/2.45.2", "accept": "*/*", "accept-encoding": "deflate, gzip, br, zstd", "accept-language": "en-US, *;q=0.9", "pragma": "no-cache", "git-protocol": "version=2"}, body: Body(Empty) }) upstream_repo="/nixos/nixpkgs.git" remote_auth=Http { auth: Handle { value: None } } remote_url="https://github.com/nixos/nixpkgs.git" head_ref=Some("HEAD") head_ref_resolved=None force=false
2024-08-20T17:33:24.047420Z TRACE handle_http_request:call_service:fetch_upstream:fetch_refs_from_url:command_env: josh::shell: stdout="" stderr="From https://github.com/nixos/nixpkgs\n   7364d718e172..9aacff10553b  haskell-updates -> refs/josh/upstream/nixos%2Fnixpkgs.git/refs/heads/haskell-updates\n * [new branch]                init-harper-1724005626 -> refs/josh/upstream/nixos%2Fnixpkgs.git/refs/heads/init-harper-1724005626\n   efdf121eb0a6..08d4eb0924a7  master     -> refs/josh/upstream/nixos%2Fnixpkgs.git/refs/heads/master\n   4a92571f9207..c42fcfbdfeae  nixos-24.05 -> refs/josh/upstream/nixos%2Fnixpkgs.git/refs/heads/nixos-24.05\n   acbbdd548480..3f38e71a8e23  nixos-24.05-small -> refs/josh/upstream/nixos%2Fnixpkgs.git/refs/heads/nixos-24.05-small\n   a58bc8ad7796..8a3354191c0d  nixos-unstable -> refs/josh/upstream/nixos%2Fnixpkgs.git/refs/heads/nixos-unstable\n   9ccfa8772180..d2fa2514f041  nixos-unstable-small -> refs/josh/upstream/nixos%2Fnixpkgs.git/refs/heads/nixos-unstable-small\n   5e9cedadfd22..595a924170d8  nixpkgs-24.05-darwin -> refs/josh/upstream/nixos%2Fnixpkgs.git/refs/heads/nixpkgs-24.05-darwin\n   daf7bb95821b..f02fa2f654c7  nixpkgs-unstable -> refs/josh/upstream/nixos%2Fnixpkgs.git/refs/heads/nixpkgs-unstable\n * [new branch]                pr-a93b4f6c -> refs/josh/upstream/nixos%2Fnixpkgs.git/refs/heads/pr-a93b4f6c\n * [new branch]                protonvpn_443 -> refs/josh/upstream/nixos%2Fnixpkgs.git/refs/heads/protonvpn_443\n   6f3340bf0f88..13dc2d792d5d  r-updates  -> refs/josh/upstream/nixos%2Fnixpkgs.git/refs/heads/r-updates\n   d8fd1dd81c18..5a1c1795151c  release-24.05 -> refs/josh/upstream/nixos%2Fnixpkgs.git/refs/heads/release-24.05\n * [new branch]                revert-314299-auto-update/dhcpcd -> refs/josh/upstream/nixos%2Fnixpkgs.git/refs/heads/revert-314299-auto-update/dhcpcd\n   e0626c756e05..b9d53f4e0f83  staging    -> refs/josh/upstream/nixos%2Fnixpkgs.git/refs/heads/staging\n   20b1cf15fad8..3a81601d9c3f  staging-24.05 -> refs/josh/upstream/nixos%2Fnixpkgs.git/refs/heads/staging-24.05\n   d22bd4ff5a1a..a0cf0dbf0050  staging-next -> refs/josh/upstream/nixos%2Fnixpkgs.git/refs/heads/staging-next\n   060ba11d60d1..4c70595a733b  staging-next-24.05 -> refs/josh/upstream/nixos%2Fnixpkgs.git/refs/heads/staging-next-24.05\n * [new branch]                update-nix-2.24 -> refs/josh/upstream/nixos%2Fnixpkgs.git/refs/heads/update-nix-2.24" url.path="/nixos/nixpkgs.git:/lib.git/info/refs" http.request.method="GET" req_auth=(Handle { value: None }, Request { method: GET, uri: /nixos/nixpkgs.git:/lib.git/info/refs?service=git-upload-pack, version: HTTP/1.1, headers: {"host": "localhost:8000", "user-agent": "git/2.45.2", "accept": "*/*", "accept-encoding": "deflate, gzip, br, zstd", "accept-language": "en-US, *;q=0.9", "pragma": "no-cache", "git-protocol": "version=2"}, body: Body(Empty) }) upstream_repo="/nixos/nixpkgs.git" remote_auth=Http { auth: Handle { value: None } } remote_url="https://github.com/nixos/nixpkgs.git" head_ref=Some("HEAD") head_ref_resolved=None force=false cmd=["git", "fetch", "--prune", "--no-tags", "https://github.com/nixos/nixpkgs.git", "+HEAD*:refs/josh/upstream/nixos%2Fnixpkgs.git/HEAD*", "+refs/josh/*:refs/josh/upstream/nixos%2Fnixpkgs.git/refs/josh/*", "+refs/heads/*:refs/josh/upstream/nixos%2Fnixpkgs.git/refs/heads/*", "+refs/tags/*:refs/josh/upstream/nixos%2Fnixpkgs.git/refs/tags/*"] env=[]
2024-08-20T17:33:24.047493Z DEBUG handle_http_request:call_service:fetch_upstream:fetch_refs_from_url: josh_proxy: fetch_refs_from_url done ["git", "fetch", "--prune", "--no-tags", "https://github.com/nixos/nixpkgs.git", "+HEAD*:refs/josh/upstream/nixos%2Fnixpkgs.git/HEAD*", "+refs/josh/*:refs/josh/upstream/nixos%2Fnixpkgs.git/refs/josh/*", "+refs/heads/*:refs/josh/upstream/nixos%2Fnixpkgs.git/refs/heads/*", "+refs/tags/*:refs/josh/upstream/nixos%2Fnixpkgs.git/refs/tags/*"] "/data/git/mirror" "From https://github.com/nixos/nixpkgs\n   7364d718e172..9aacff10553b  haskell-updates -> refs/josh/upstream/nixos%2Fnixpkgs.git/refs/heads/haskell-updates\n * [new branch]                init-harper-1724005626 -> refs/josh/upstream/nixos%2Fnixpkgs.git/refs/heads/init-harper-1724005626\n   efdf121eb0a6..08d4eb0924a7  master     -> refs/josh/upstream/nixos%2Fnixpkgs.git/refs/heads/master\n   4a92571f9207..c42fcfbdfeae  nixos-24.05 -> refs/josh/upstream/nixos%2Fnixpkgs.git/refs/heads/nixos-24.05\n   acbbdd548480..3f38e71a8e23  nixos-24.05-small -> refs/josh/upstream/nixos%2Fnixpkgs.git/refs/heads/nixos-24.05-small\n   a58bc8ad7796..8a3354191c0d  nixos-unstable -> refs/josh/upstream/nixos%2Fnixpkgs.git/refs/heads/nixos-unstable\n   9ccfa8772180..d2fa2514f041  nixos-unstable-small -> refs/josh/upstream/nixos%2Fnixpkgs.git/refs/heads/nixos-unstable-small\n   5e9cedadfd22..595a924170d8  nixpkgs-24.05-darwin -> refs/josh/upstream/nixos%2Fnixpkgs.git/refs/heads/nixpkgs-24.05-darwin\n   daf7bb95821b..f02fa2f654c7  nixpkgs-unstable -> refs/josh/upstream/nixos%2Fnixpkgs.git/refs/heads/nixpkgs-unstable\n * [new branch]                pr-a93b4f6c -> refs/josh/upstream/nixos%2Fnixpkgs.git/refs/heads/pr-a93b4f6c\n * [new branch]                protonvpn_443 -> refs/josh/upstream/nixos%2Fnixpkgs.git/refs/heads/protonvpn_443\n   6f3340bf0f88..13dc2d792d5d  r-updates  -> refs/josh/upstream/nixos%2Fnixpkgs.git/refs/heads/r-updates\n   d8fd1dd81c18..5a1c1795151c  release-24.05 -> refs/josh/upstream/nixos%2Fnixpkgs.git/refs/heads/release-24.05\n * [new branch]                revert-314299-auto-update/dhcpcd -> refs/josh/upstream/nixos%2Fnixpkgs.git/refs/heads/revert-314299-auto-update/dhcpcd\n   e0626c756e05..b9d53f4e0f83  staging    -> refs/josh/upstream/nixos%2Fnixpkgs.git/refs/heads/staging\n   20b1cf15fad8..3a81601d9c3f  staging-24.05 -> refs/josh/upstream/nixos%2Fnixpkgs.git/refs/heads/staging-24.05\n   d22bd4ff5a1a..a0cf0dbf0050  staging-next -> refs/josh/upstream/nixos%2Fnixpkgs.git/refs/heads/staging-next\n   060ba11d60d1..4c70595a733b  staging-next-24.05 -> refs/josh/upstream/nixos%2Fnixpkgs.git/refs/heads/staging-next-24.05\n * [new branch]                update-nix-2.24 -> refs/josh/upstream/nixos%2Fnixpkgs.git/refs/heads/update-nix-2.24" url.path="/nixos/nixpkgs.git:/lib.git/info/refs" http.request.method="GET" req_auth=(Handle { value: None }, Request { method: GET, uri: /nixos/nixpkgs.git:/lib.git/info/refs?service=git-upload-pack, version: HTTP/1.1, headers: {"host": "localhost:8000", "user-agent": "git/2.45.2", "accept": "*/*", "accept-encoding": "deflate, gzip, br, zstd", "accept-language": "en-US, *;q=0.9", "pragma": "no-cache", "git-protocol": "version=2"}, body: Body(Empty) }) upstream_repo="/nixos/nixpkgs.git" remote_auth=Http { auth: Handle { value: None } } remote_url="https://github.com/nixos/nixpkgs.git" head_ref=Some("HEAD") head_ref_resolved=None force=false
2024-08-20T17:33:24.047935Z  INFO handle_http_request:call_service:fetch_upstream:get_head: josh_proxy: get_head ["git", "ls-remote", "--symref", "https://github.com/nixos/nixpkgs.git", "HEAD"] "/data/git/mirror" "" url.path="/nixos/nixpkgs.git:/lib.git/info/refs" http.request.method="GET" req_auth=(Handle { value: None }, Request { method: GET, uri: /nixos/nixpkgs.git:/lib.git/info/refs?service=git-upload-pack, version: HTTP/1.1, headers: {"host": "localhost:8000", "user-agent": "git/2.45.2", "accept": "*/*", "accept-encoding": "deflate, gzip, br, zstd", "accept-language": "en-US, *;q=0.9", "pragma": "no-cache", "git-protocol": "version=2"}, body: Body(Empty) }) upstream_repo="/nixos/nixpkgs.git" remote_auth=Http { auth: Handle { value: None } } remote_url="https://github.com/nixos/nixpkgs.git" head_ref=Some("HEAD") head_ref_resolved=None force=false
...

~~It just keeps outputting logs like this until I kill it~~

If I wait a really long time, it finally goes through? Is this because nixpkgs is just exceptionally large, perhaps? Or maybe a ratelimit on GH's end?

edit just did another test that took over 10 minutes to resolve. Probably a rate-limit do to missing auth, I can't seem to figure out how or if auth get's passed through at all, though. The logs seem to indicate that its not. I am using a git credential helper that I've already confirmed works when outside of josh.

nrdxp commented 3 weeks ago

I've updated the original post to reflect my evolving understanding of the issue. Initially thought to be an authentication problem, then a potential infinite loop, it now appears to be a performance issue possibly related to rate limiting (which might be due to missing auth). The updated OP provides a more accurate description of the observed behavior and potential causes.

christian-schilling commented 3 days ago

I don't think this is due to missing auth. As far as I understand the git client will always first attempt to do the request without auth and then only supply credentials when the server asks for them.

For cloning a public repo there should be no credentials required. So I'm wondering why this is an issue. The clone should just succeed without credentials being transmitted.

Regarding performance: nixpgks is quite large. And has quite a few refs (not extreme but still). One thing to see if the number of refs is the issue would be to try: git clone https://<josh>/nixpkgs.git@refs/heads/master:/.git nixpkgs which limits the fetch/clone to a single ref.

On a first clone it is also expected to take some time for such a large repo, however follow up fetch/pull (or clone using the same proxy instance) should be fast though.

Another thing would be to try josh@ 012f8dccee60fbdb176a032c4d5b88ae03f780c2 as I do suspect a bug regarding auth/performance has been introduced after, but I was not able to reproduce it so far.

josh-project / josh