Skip to content

Long delay using gh pr checkout (or gh itself?) #458

Description

@dwijnand

Describe the bug

I'm finding using gh pr checkout to take a long time (e.g 19 seconds). But not that it's my only use of gh so it might be gh itself, not specific to pr checkout. gh version 0.5.4 (2020-02-04).

Steps to reproduce the behavior

  1. Run gh pr checkout
  2. Notice how long it takes (19 seconds for me)

Expected vs actual behavior

I'm accustomed to hub not taking so long.

Logs

I'll share a screenshot as it has the timestamps:

image

Activity

  1. changed the title [-]Long delay when using gh pr checkout (or maybe just gh itself)[/-] [+]Long delay when using gh pr checkout (or just gh itself?)[/+] on Feb 15, 2020
  2. changed the title [-]Long delay when using gh pr checkout (or just gh itself?)[/-] [+]Long delay using gh pr checkout (or gh itself?)[/+] on Feb 15, 2020
  3. mislav commented on Feb 17, 2020

    @mislav
    Contributor

    @dwijnand Thank you for reporting! The timestamps output looks very useful; how did you generate it?

    You can set the DEBUG=1 gh ... environment variable to opt into verbose mode, which will show API requests. Use DEBUG=api to get more information about HTTP traffic. Does that shed some light on which particular request is slow?

    Also, how many git remotes does your repository have?

  4. dwijnand commented on Feb 17, 2020

    @dwijnand
    Author

    That's ITerm2's timestamp feature (https://www.iterm2.com/features.html).

    It was with only 1 git remote (origin). I'll try to remember to debug next time to get the logs. Does DEBUG=1 include the HTTP traffic?

  5. mislav commented on Feb 17, 2020

    @mislav
    Contributor

    DEBUG=1 only lists the types of HTTP requests and their URLs but not their content, so all GraphQL requests will look identical: POST /graphql. If there are multiple GraphQL request, you should use DEBUG=api to differentiate between them, but then there is much more output.

    Thank you!

  6. abdel-ships-it commented on Feb 19, 2020

    @abdel-ships-it

    I am having the same issue with gh pr create on version 0.5.4. It takes so long I can open the project repo in the browser, and create the PR there in the meantime.

  7. TheKevJames commented on Feb 23, 2020

    @TheKevJames

    I'm finding a very similar issue. What was very interesting to me and might potentially help in tracking this down is the vast difference between hub and gh here -- perhaps there's some extra step we're doing in gh that is unnecessary? Comparison (using the excellent hyperfine utility for benchmarking):

    » hyperfine 'hub pr list' 'gh pr list'
    Benchmark #1: hub pr list
      Time (mean ± σ):     968.0 ms ± 404.3 ms    [User: 77.6 ms, System: 50.0 ms]
      Range (min … max):   724.4 ms … 2049.4 ms    10 runs
    
      Warning: The first benchmarking run for this command was significantly slower than the rest (2.049 s). This could be caused by (filesystem) caches that were not filled until after the first run. You should consider using the '--warmup' option to fill those caches before the actual benchmark. Alternatively, use the '--prepare' option to clear the caches before each timing run.
    
    Benchmark #2: gh pr list
      Time (mean ± σ):      3.930 s ±  0.232 s    [User: 101.5 ms, System: 96.9 ms]
      Range (min … max):    3.732 s …  4.338 s    10 runs
    
    Summary
      'hub pr list' ran
        4.06 ± 1.71 times faster than 'gh pr list'
    

    So a few interesting things to note there:

    • hub's first run was "slow" at 2s but future runs we closer to half that -- is it perhaps doing some sort of caching gh could emulate?
    • overall, gh is roughly 4x slower than hub

    Diving in deeper with DEBUG=api gh pr list I can see that the slow request is the first one:

    » DEBUG=api gh pr list
    [git remote -v]
    POST /graphql
    {"query":"\n\tfragment repo on Repository {\n\t\tid\n\t\tname\n\t\towner { login }\n\t\tviewerPermission\n\t\tdefaultBranchRef {\n\t\t\tname\n\t\t\ttarget { oid }\n\t\t}\n\t\tisPrivate\n\t}\n\tquery {\n\t\tviewer { login }\n\t\t\n\t\trepo_000: repository(owner: \"apple\", name: \"sauce\") {\n\t\t\t...repo\n\t\t\tparent {\n\t\t\t\t...repo\n\t\t\t}\n\t\t}\n\t\t\n\t}\n\t","variables":null}
    < HTTP 200 OK
    

    Comparing again to hub with HUB_VERBOSE=1 hub pr list, I see it has no equivalent to that first request:

    » HUB_VERBOSE=1 hub pr list
    $ git rev-parse -q --git-dir
    $ git remote -v
    $ git config --get-all hub.host
    > GET https://api.github.com/repos/apple/sauce/pulls?per_page=100&direction=desc
    > Authorization: token [REDACTED]
    > Accept: application/vnd.github.shadow-cat-preview+json;charset=utf-8
    < HTTP 200
    

    Its hard to get an exact timing off of this, but visually it appears like all the extra latency in gh compared to hub comes from that extra POST /graphql which occurs before asking for the pull request data. It appears the /graphql endpoint might be slightly slower than the older endpoint used by hub, but that does not appear to be the largest cause of performance issues at this point.


    Version info:

    » uname -a
    Darwin my-hostname 19.2.0 Darwin Kernel Version 19.2.0: Sat Nov  9 03:47:04 PST 2019; root:xnu-6153.61.1~20/RELEASE_X86_64 x86_64
    » hub --version
    git version 2.21.0 (Apple Git-122.2)
    hub version 2.14.1
    » gh --version
    gh version 0.5.7 (2020-02-20)
    https://github.com/cli/cli/releases/tag/v0.5.7
    » hyperfine --version
    hyperfine 1.9.0
    

    10 pulls open in repo, 288 closed

  8. mislav commented on Feb 24, 2020

    @mislav
    Contributor

    @TheKevJames Thanks for those benchmarks!

    The first GraphQL request that gh performs is look up GitHub repos pointed to by your git remotes, which it then uses to guess the base repository for querying issues, PRs, etc.

    This lookup is repetitive and we're considering caching the result so it doesn't slow down all operations across the board.

  9. TheKevJames commented on Feb 24, 2020

    @TheKevJames

    Interesting -- I wonder why we need to look that up via GraphQL? git remote -v should already have the URLs for those repos with no need for a network request. Note to self: check out the code for this.

  10. dwijnand commented on Feb 26, 2020

    @dwijnand
    Author

    I just ran my second gh pr checkout since Mislav's instructions and in both cases it was fast, like 5 seconds instead of the 19 when I opened the issue. So I'm happy to call this issue fixed.

  11. TheKevJames commented on Feb 26, 2020

    @TheKevJames

    Probably best to leave this issue open until @mislav 's comment on caching gets addressed, since (personally, at least) I wouldn't really consider 5s to checkout a git branch to be good enough. Awesome to hear there've been such significant improvements already, though!

  12. mislav commented on Feb 26, 2020

    @mislav
    Contributor

    I wonder why we need to look that up via GraphQL? git remote -v should already have the URLs for those repos with no need for a network request.

    That's true, but we also analyze the relationship of those repos to see which is the parent or a fork of which. If you have 3 git remotes, we don't know just from their URLs which one is the "base" remote, which one is your fork, and which is an unrelated fork from another contributor whose branch you merely wanted to check out.

  13. TheKevJames commented on Feb 26, 2020

    @TheKevJames

    Ooh, interesting! That makes sense, I see how that could make things complicated. I wonder if its worth thinking through some sort of "degraded mode" here? Sounds like we could avoid some work in simple cases; ie. the performance test I did above was in a case where there was only one remote anyway -- if there's only one remote, do we need to do this check at all? Or for personal projects, it might be the case that a user doesn't particularly care about forks for a given feature -- maybe a --only-look-at-origin flag could be valuable?

    ^ that's more spitballing than anything else; I imagine the caching would solve this "well enough" to not have to worry about added performance optimizations, just figured I'd toss out some ideas!

  14. mislav commented on Feb 28, 2020

    @mislav
    Contributor

    if there's only one remote, do we need to do this check at all?

    What should happen if you cloned a fork of yours? When you type gh pr create inside that fork, should the PR be sent against your fork, or to the parent repo by default? We opted for the latter, since that best encapsulates how people contribute to open source software, but in order to do that we need to look up the remote (even if it's only 1 git remote) to find out whether the current repo is a fork or a "source" repo.

  15. TheKevJames commented on Feb 28, 2020

    @TheKevJames

    Ah, wasn't thinking of the gh pr create case -- that does indeed make sense. I suppose the same logic would apply for gh pr status and gh pr checkout (eg. you might want to check status on PRs against the upstream repo of your fork).

    Hmm, in that case, perhaps that --only-look-at-origin flag would be reasonable. Or some way to configure that per-repo more permanently? It occurs to me there are times when you would want the opposite behavior as well:

    • "I maintain a fork, I don't want to see PRs against upstream when I'm working on this repo"
    • "Ownership of the repo/fork has changed, upstream is never relevant", eg. for my repo here, my fork is the "source of truth" for that project as the original is unmaintained.
  16. mislav commented on Feb 28, 2020

    @mislav
    Contributor

    Or some way to configure that per-repo more permanently? It occurs to me there are times when you would want the opposite behavior as well:

    Good thinking! We already got asked about this #350 and we're planning to build support for the user indicating what is their preferred relationship between the repositories (i.e. what is the default base repository, the default push repository for PR branches, etc)

  17. vilmibm commented on May 13, 2020

    @vilmibm
    Contributor

    It seems like this discussion ended up in a pretty different place than when it started. @mislav are you aware of a better issue that captures adding the ability for users to explicitly set the relationship between remotes? If not, I can create one. Either way I think we can close this once we have someplace to point to.

  18. mislav commented on May 13, 2020

    @mislav
    Contributor

    @vilmibm Good call! I think the open tickets that we have that touch on remote relationships are these ones: #867 #790 #317

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Metadata

Metadata

Assignees

No one assigned

    Labels

    Type

    No type

    Projects

    No projects

      Milestone

      No milestone

      Relationships

      None yet

      Development

      No branches or pull requests

      Issue actions