Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

magithub-issue-repo is very slow on my machine #349

Open
rgrinberg opened this issue Jul 18, 2018 · 20 comments
Open

magithub-issue-repo is very slow on my machine #349

rgrinberg opened this issue Jul 18, 2018 · 20 comments
Labels
performance concerned with efficiency or response times

Comments

@rgrinberg
Copy link

magithub-issue-repo is a bottleneck on my machine when bringing up the github status.

This is likely because of the ghub--host call:

(defun ghub--host (&optional forge)
  (if (eq forge 'gitlab)
      (or (ignore-errors (car (process-lines "git" "config" "gitlab.host")))
          (bound-and-true-p glab-default-host))
    (or (ignore-errors (car (process-lines "git" "config" "github.host")))
        ghub-default-host)))

It's quite slow to have to shell out to git for every single issue for a large enough list of issues. It would be much better to call this once for the list of issues, or even better to remember this value per repo. It's not very likely that this host value is going to change very often.

@vermiculus
Copy link
Owner

vermiculus commented Jul 18, 2018

Nice catch. I'm wondering if such a cache (probably just a hash table 'root-dir -> value'; local memory only) should go into ghub though so magit can directly benefit as well. @tarsius, what do you think?

@tarsius
Copy link
Contributor

tarsius commented Jul 18, 2018

Magit already has such a cache, but because ghub uses process-line instead of magit-get that isn't being used. Maybe ghub--host should use magit-get if available, but after optimizing everything else, that would only save us a single fork.

Why do you call ghub--host once per issue? I would expect that it should be fairly easy to optimize that away.

@vermiculus
Copy link
Owner

vermiculus commented Jul 18, 2018

It could be that it's the cache that's calling this so many times. When we cache an API call, ghub--host is called to contextualize that request (to handle working across multiple repositories). That's probably the culprit.

Code references:


Actually, that's not it. It's a lot simpler than that, though some performance improvements could be made to the cache here (since I'm pretty confident the context includes the host). We actually call ghub--host in building the regex used to parse the HTTP address into discrete pieces of data to build something to parse a repo out of.

I don't recall what magithub-issue-repo itself is used for, but it's probably to setup repository context for that section.

@vermiculus
Copy link
Owner

The dashboard does bucket issues by repo using this function. Is that the workflow we're seeing it in?

magithub/magithub-dash.el

Lines 196 to 198 in 8cf40f5

(magithub-core-bucket-multi issues
#'magithub-issue-repo
(lambda (repo) (alist-get 'owner repo)))))

@rgrinberg
Copy link
Author

Here's a complete trace from the profiler:

- command-execute                                                 631  95%
 - call-interactively                                             631  95%
  - funcall-interactively                                         627  95%
   - magit-status                                                 627  95%
    - magit-status-internal                                       627  95%
     - magit-mode-setup                                           627  95%
      - magit-mode-setup-internal                                 627  95%
       - magit-refresh-buffer                                     622  94%
        - apply                                                   620  94%
         - magit-status-refresh-buffer                            618  93%
          - magit-run-section-hook                                616  93%
           - run-hooks                                            616  93%
            - magithub-issue--insert-issue-section                506  76%
             - magithub-issue-insert-sections                     506  76%
              - mapcar                                            506  76%
               - #<compiled 0x477a2c21>                           506  76%
                - magithub-issue-insert-section                   505  76%
                 - run-hook-with-args                             346  52%
                  - magithub-issue-detail-insert-personal-notes                134  20%
                   - magithub-issue-has-personal-note-p                133  20%
                    - magithub-issue-personal-note-file                129  19%
                     - magithub-issue-repo                        129  19%
                      + ghubp-host                                129  19%
                   + magit-section                                  1   0%
                  + magithub-issue-detail-insert-created                 94  14%
                  + magithub-issue-detail-insert-body-preview                 54   8%
                  + magithub-issue-detail-insert-updated                 16   2%
                  + magithub-issue-detail-insert-labels                  6   0%
                  + magithub-issue-detail-insert-assignees                  4   0%
                  + magithub-issue-detail-insert-author                  2   0%
                 + magithub-issue-has-personal-note-p                151  22%
                 + magit-get-section                                2   0%
                 + run-hook-with-args-until-success                  1   0%
                 + magit-section-ident                              1   0%
            - magithub-issue--insert-pr-section                    81  12%
             - magithub-issue-insert-sections                      81  12%
              - mapcar                                             81  12%
               - #<compiled 0x462c06c9>                            81  12%
                - magithub-issue-insert-section                    81  12%
                 - run-hook-with-args                              54   8%
                  - magithub-issue-detail-insert-personal-notes                 26   3%
                   - magithub-issue-has-personal-note-p                 25   3%
                    - magithub-issue-personal-note-file                 23   3%
                     - magithub-issue-repo                         23   3%
                      - ghubp-host                                 23   3%
                       - ghub--host                                23   3%
                        - process-lines                            23   3%
                           apply                                   23   3%

Actually, there are many code paths that end up calling ghubp-host. The main slow down is indeed form inserting the issues via magithub-issue-insert-sections.

@vermiculus
Copy link
Owner

You can take magithub-issue-detail-insert-personal-notes out of your magithub-issue-details-hook.

I feel like we should still cache ghub--host. @tarsius -- would you be open to a PR setting up something basic without adding a hard dependency on magit?

@vermiculus
Copy link
Owner

I'd be interested to see what's taking magithub-issue-detail-insert-created so long, too -- could you insert that here? Is there anything specifically that can be improved?

@vermiculus vermiculus added the performance concerned with efficiency or response times label Jul 20, 2018
@rgrinberg
Copy link
Author

I don't have the trace, but I remember the trace but I remember where the slowness came from. The datetime parsing was actually quite slow: parse-iso8601-time-string

@tarsius
Copy link
Contributor

tarsius commented Jul 20, 2018

I feel like we should still cache ghub--host. @tarsius -- would you be open to a PR setting up something basic without adding a hard dependency on magit?

Please do that in ghubp-host for now. I think you should only cache during a single refresh using magit--with-refresh-cache. Look at magit-toplevel and others for usage examples.

@vermiculus
Copy link
Owner

Will do. I made some commits last night that implements -- for now -- a simple time-based cache of git-config information. Once I get home, I'll clean those up and push -- we'll see how that affects performance here.

I'd like to avoid adding a hard dependency on magit, but I've no issue with using it if available. I'll see what macro-magic I can do tonight.

@ibizaman
Copy link
Contributor

ibizaman commented Nov 25, 2018

Hi, I came to your conclusions independently:

  • ghub--host is slow
  • parse-iso8601-time-string is slow
    This impacts a lot the performances in repos with a lot of opened PRs.

For ghub--host, here is my profile trace:

- ...                              811  40%
 - list                            727  36%
  - cons                           727  36%
   - magithub-repo                 727  36%
    - magithub-issue-repo          727  36%
     - let                         727  36%
      - let                        727  36%
       - or                        727  36%
        - let                      727  36%
         - unwind-protect          727  36%
          - progn                  727  36%
           - if                    727  36%
            - string-match         727  36%
             - concat              727  36%
              - regexp-quote       727  36%
               - ghubp-host        727  36%
                - ghub--host       727  36%
                 - process-lines   726  36%
                    apply          710  35%

To solve this I came up with the same idea, using a hash table. By changing the code in ghub.el to the following, I get no performance impact anymore.

(defun ghub--host (&optional forge)
  (when (not (hash-table-p ghub--host-result))
    (setq ghub--host-result (make-hash-table :test 'equal)))

  (if-let* ((result (gethash default-directory ghub--host-result nil)))
      result
    (puthash default-directory
             (cl-ecase forge
               ((nil github)
                (or (ignore-errors (car (process-lines "git" "config" "github.host")))
                    ghub-default-host))
               (gitlab
                (or (ignore-errors (car (process-lines "git" "config" "gitlab.host")))
                    (bound-and-true-p glab-default-host)))
               (gitea
                (or (ignore-errors (car (process-lines "git" "config" "gitea.host")))
                    (bound-and-true-p gtea-default-host)))
               (gogs
                (or (ignore-errors (car (process-lines "git" "config" "gogs.host")))
                    (bound-and-true-p gogs-default-host)))
               (bitbucket
                (or (ignore-errors (car (process-lines "git" "config" "bitbucket.host")))
                    (bound-and-true-p buck-default-host))))
             ghub--host-result)))

(defvar ghub--host-result (make-hash-table :test string-equal)
  "Cache result of ghub--host.")

Now, the issue is how to correctly refresh the cache.

For parse-iso8601-time-string, here is my profile trace:

- magit-status                                                                     602  30%
 - magit-status-internal                                                           602  30%
  - magit-mode-setup                                                               602  30%
   - magit-mode-setup-internal                                                     602  30%
    - magit-refresh-buffer                                                         593  29%
     - apply                                                                       590  29%
      - magit-status-refresh-buffer                                                581  29%
       - magit-run-section-hook                                                    579  29%
        - apply                                                                    579  29%
         - magithub-issue--insert-pr-section                                       550  27%
          - if                                                                     550  27%
           - progn                                                                 550  27%
            - magithub-issue--insert-generic-section                               550  27%
             - when-let                                                            550  27%
              - if-let                                                             550  27%
               - if-let*                                                           550  27%
                - let*                                                             550  27%
                 - if                                                              550  27%
                  - magit-insert-section                                           550  27%
                   - let*                                                          550  27%
                    - let                                                          550  27%
                     - catch                                                       550  27%
                      - magithub-issue-insert-sections                             540  27%
                       - let                                                       540  27%
                        - mapcar                                                   540  27%
                         - #<lambda 0x31fb009add22e73a>                            540  27%
                          - magithub-issue-insert-section                          540  27%
                           - if                                                    540  27%
                            - progn                                                540  27%
                             - let*                                                540  27%
                              - let                                                535  26%
                               - catch                                             535  26%
                                - let                                              531  26%
                                 - let                                             531  26%
                                  - run-hook-with-args                             516  25%
                                   - magithub-issue-detail-insert-created          362  18%
                                    - let                                          362  18%
                                     - let                                         362  18%
                                      - insert                                     362  18%
                                       - propertize                                361  18%
                                        - magithub--format-time                    361  18%
                                         - format-time-string                      361  18%
                                          - or                                     361  18%
                                           - and                                   361  18%
                                            - magithub--parse-time-string          361  18%
                                             - parse-iso8601-time-string           361  18%
                                                apply                              361  18%
                                   - magithub-issue-detail-insert-body-preview      57   2%
                                    - let                                           57   2%
                                     - let                                          57   2%
                                      - let                                         57   2%
                                       - if                                         54   2%
                                        - setq                                      51   2%
                                         - let                                      51   2%
                                          - s-trim                                  51   2%
                                           - magithub-indent-text                   49   2%
                                            - magithub-fill-gfm                     48   2%
                                             - let                                  48   2%
                                              - save-current-buffer                 44   2%
                                               - unwind-protect                     44   2%
                                                - progn                             44   2%
                                                 - progn                            44   2%
                                                  - let                             44   2%
                                                   - fill-region                    20   1%
                                                    + fill-region-as-paragraph      15   0%
                                                    + fill-forward-paragraph         5   0%
                                                   + font-lock-ensure               17   0%
                                                   + gfm-mode                        7   0%
                                                generate-new-buffer                  3   0%
                                              replace-regexp-in-string               1   0%
                                             s-trim-left                             2   0%
                                        + if                                         1   0%
                                         setq                                        1   0%
                                   + magithub-issue-detail-insert-personal-notes    23   1%
                                   + magithub-issue-detail-insert-assignees         23   1%
                                   + magithub-issue-detail-insert-author            20   1%
                                   + magithub-issue-detail-insert-labels            20   1%
                                   + magithub-issue-detail-insert-updated           10   0%

I went the very crude way to replace magithub--parse-time-string with:

(defun magithub--parse-time-string (iso8601)
  "Parse ISO8601 into a time value.
ISO8601 is expected to not have a TZ component."
  (let ((year (string-to-number (substring iso8601 0 4)))
        (month (string-to-number (substring iso8601 5 7)))
        (day (string-to-number (substring iso8601 8 10)))
        (hour (string-to-number (substring iso8601 11 13)))
        (minute (string-to-number (substring iso8601 14 16)))
        (second (string-to-number (substring iso8601 17 19)))
        (day-of-week nil)
        (dst nil)
        (tz 0))
    (encode-time second minute hour day month year t)))

No error detection is made here, we should check string-to-number return != 0 number. If not, fallback to parse-iso8601-time-string.

Now again, no performance impact anymore.

With those two performance bottlenecks out of the way, the remaining profile trace is:

- magithub-issue--insert-generic-section                               517  59%
 - when-let                                                            517  59%
  - if-let                                                             517  59%
   - if-let*                                                           517  59%
    - let*                                                             517  59%
     - if                                                              517  59%
      - magit-insert-section                                           517  59%
       - let*                                                          517  59%
        - let                                                          517  59%
         - catch                                                       517  59%
          - magithub-issue-insert-sections                             512  58%
           - let                                                       512  58%
            - mapcar                                                   512  58%
             - #<lambda 0x31fb009add22e73a>                            512  58%
              - magithub-issue-insert-section                          512  58%
               - if                                                    512  58%
                - progn                                                512  58%
                 - let*                                                512  58%
                  - let                                                502  57%
                   - catch                                             502  57%
                    - let                                              494  56%
                     - let                                             494  56%
                      - magit-insert-heading                           331  38%
                       - format                                        331  38%
                        - propertize                                   330  38%
                         - if                                          328  37%
                          - magithub-issue-has-personal-note-p         328  37%
                           - let                                       328  37%
                              and                                      313  36%
                            + magithub-issue-personal-note-file         15   1%
                      - run-hook-with-args                             163  18%
                       - magithub-issue-detail-insert-body-preview      61   7%
                        - let                                           61   7%
                         - let                                          61   7%
                          - let                                         61   7%
                           - if                                         59   6%
                            - setq                                      54   6%
                             - let                                      53   6%
                              - s-trim                                  53   6%
                               - magithub-indent-text                   52   5%
                                - magithub-fill-gfm                     49   5%
                                 - let                                  49   5%
                                  - save-current-buffer                 44   5%
                                   - unwind-protect                     44   5%
                                    - progn                             43   4%
                                     - progn                            43   4%
                                      - let                             43   4%
                                       + fill-region                    16   1%
                                       + font-lock-ensure               12   1%
                                       + gfm-mode                       12   1%
                                       + insert                          2   0%
                                      and                                1   0%
                                    generate-new-buffer                  5   0%
                                  replace-regexp-in-string               3   0%
                                 s-trim-right                            1   0%
                       - magithub-issue-detail-insert-personal-notes    27   3%
                        - let*                                          26   2%
                         - let                                          26   2%
                          - catch                                       26   2%
                           - insert                                     26   2%
                            - if                                        26   2%
                             + magithub-issue-has-personal-note-p       26   2%
                       + magithub-issue-detail-insert-author            27   3%
                       + magithub-issue-detail-insert-labels            18   2%
                       + magithub-issue-detail-insert-assignees         16   1%
                       + magithub-issue-detail-insert-updated            8   0%
                       + magithub-issue-detail-insert-created            5   0%

Looks like optimizing magithub-issue-has-personal-note-p could help further. I'll probably check that this week.

@rgrinberg
Copy link
Author

Excellent work @ibizaman!

@ibizaman
Copy link
Contributor

ibizaman commented Nov 26, 2018

I've been thinking about where to put the code to cache the result of ghub--host. I actually don't think it should be in https://github.com/magit/ghub/blob/master/ghub.el like I posted above.

Caching should be done somewhere in magithub, as magithub is the only one that knows when to refresh the cache. Like proposed by @tarsius, that should be done somewhere in magit--with-refresh-cache.

That being said, I glanced over that function and have no idea how to use it to refresh the ghub--host cache. 😅 Any help appreciated.

@ibizaman
Copy link
Contributor

ibizaman commented Nov 28, 2018

Jumping ahead and replacing that whole magithub-issue-has-personal-note-p with just a function returning nil, and also removing the remaining stacktrace is:

- magithub-issue--insert-generic-section          288  54%
 [...]
 - magit-insert-section                           288  54%
 [...]
  - magithub-issue-insert-sections                287  54%
  [...]
   - magithub-issue-insert-section                287  54%
   [...]
    - run-hook-with-args                          259  48%
     - magithub-issue-detail-insert-body-preview  123  23%
     [...]
      - magithub-indent-text                      103  19%
       - magithub-fill-gfm                         99  18%
       [...]
        + fill-region                              36   6%
        + font-lock-ensure                         31   5%
        + gfm-mode                                 22   4%
        + insert                                    3   0%
     - magithub-issue-detail-insert-author         47   8%
      [...]
      - magithub-user                              19   3%
       + magithub-cache                            19   3%
     + magithub-issue-detail-insert-assignees      29   5%
     + magithub-issue-detail-insert-labels         26   4%
     + magithub-issue-detail-insert-created        20   3%
     + magithub-issue-detail-insert-updated        11   2%

I skipped a few levels for readability.

I don't think there's an easy way around this loading time apart from lazy loading each issue.

EDIT: I can come up with a PR where the user can select with a custom variable to choose if the issues and PR info must be lazy loaded or not.

EDIT2: This slowness is not only happening on a magit-status but on every refresh. So for example in my case staging a hunk takes 5 seconds which makes the experience not enjoyable.

EDIT3: To be fair, stashing with magithub disabled still takes roughly 3 seconds.

@vermiculus
Copy link
Owner

When doing a lot of git stuff (as opposed to any github stuff), I find it helpful to quickly turn off the heavy sections completely for those few minutes. I don't have a computer with a working emacs at the moment (part of the reason it's so hard to find time for this project... ☹️) but I believe those settings are under H C. E.g., H C i can turn off issues for that repository. You can then turn them back on when you want them.

@vermiculus
Copy link
Owner

The other alternative that we could take would be changing what sections are turned on by default. Filling and fontifying the first parts of the issue body probably isn't cheap (from your profile above, about 23%). It might not give enough value for its cost.

@tarsius
Copy link
Contributor

tarsius commented Nov 28, 2018

I don't have a computer with a working emacs at the moment

😱

@ibizaman
Copy link
Contributor

@vermiculus that's a good point.

In some way, the root cause is magit needing to refresh the whole buffer on a stage operation.

@ibizaman
Copy link
Contributor

Just discovered this note about performance of magit on macos. https://magit.vc/manual/magit/MacOS-Performance.html

I'll see what speed boost I can get with that

@vermiculus
Copy link
Owner

I don't have a computer with a working emacs at the moment

😱

I know :-( my emacs computer is largely my wife's now until hers is fixed. Don't know when that will be.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
performance concerned with efficiency or response times
Projects
None yet
Development

No branches or pull requests

4 participants