bug-gnu-emacs
[Top][All Lists]
Advanced

[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index]

bug#49264: 28.0.50; project.el+tramp performance issue


From: Ergus
Subject: bug#49264: 28.0.50; project.el+tramp performance issue
Date: Wed, 30 Jun 2021 00:21:42 +0200

Hi Eli:

On Tue, Jun 29, 2021 at 03:05:35PM +0300, Eli Zaretskii wrote:
Date: Tue, 29 Jun 2021 00:11:00 +0200
From:  Ergus via "Bug reports for GNU Emacs,
 the Swiss army knife of text editors" <bug-gnu-emacs@gnu.org>

Using tramp I tried to use project.el with a command like
project-switch-to-buffer and it took like 10 minutes to complete.

I ran a profiler and I found that most of the time was taken by an
external function: global-tags-try-project-root

That doesn't follow from the profile you show.  According to the
profile, global-tags-try-project-root takes just 6% of the CPU time.

The profile is `After some optimization in an external package`. As
explained 2 paragraphs next. Before the fix it was taking more or less
the same percent than vc-responsible-backend.

project-current is called in a loop for all the opened buffers it calls
project--find-in-directory that calls project-find-functions and there
is going all the time.

I don't see project-find-functions in the profile.  Where is it and
how does it come into this picture?

project-find-functions is a hook called in project--find-in-directory

(defun project--find-in-directory (dir)
  (run-hook-with-args-until-success 'project-find-functions dir))


After some optimization in an external package; now the time is half
than before but still very slow to use the command (around 3-5 minutes
to complete) and running again the profiler I get this:

         5637  89% - command-execute
         5549  88%  - byte-code
         5549  88%   - project--read-project-buffer
         5549  88%    - let*
         5336  85%     - read-buffer
         5323  84%      - ivy-completing-read
         5323  84%       - ivy-read
         4941  78%        - ivy--reset-state
         4941  78%         - ivy--buffer-list
         4941  78%          - internal-complete-buffer
         4941  78%           - #<lambda -0x1a357caf01243d61>
         4941  78%            - and
         4941  78%             - equal
         4941  78%              - save-current-buffer
         4941  78%               - project-current
         4941  78%                - project--find-in-directory
         4548  72%                 - project-try-vc
         4537  72%                  - vc-responsible-backend
         4478  71%                   - #<compiled 0xd3f2e32af0966f7>
         4478  71%                    - vc-call-backend
         4478  71%                     - apply
         1470  23%                      + vc-svn-responsible-p
         1142  18%                      + vc-bzr-responsible-p
          970  15%                      + vc-hg-responsible-p
          390   6%                      + vc-git-responsible-p
          156   2%                      + vc-cvs-responsible-p
          126   2%                      + vc-rcs-responsible-p
          108   1%                      + vc-sccs-responsible-p
           98   1%                      + vc-src-responsible-p
           57   0%                   + tramp-file-name-handler
           11   0%                  + vc-file-getprop
          393   6%                 + global-tags-try-project-root
          375   5%        + read-from-minibuffer
           13   0%      + if
          213   3%     + project-current
           88   1%  + funcall-interactively
          572   9% + ...
           51   0% + timer-event-handler
            8   0% + redisplay_internal (C function)


As you can see most of the time is still taken by project-current and I
can't really understand why:

AFAICT, most of the time is taken by 'apply', but the profile doesn't
show which function is called by 'apply'.  Can you tell which function
is that?

apply is called in vc-responsible-backend and looking at the percentages
it is obvious that the times are going in

  23%                      + vc-svn-responsible-p
  18%                      + vc-bzr-responsible-p
  15%                      + vc-hg-responsible-p
   6%                      + vc-git-responsible-p
   2%                      + vc-cvs-responsible-p
   2%                      + vc-rcs-responsible-p
   1%                      + vc-sccs-responsible-p
   1%                      + vc-src-responsible-p
------
  68%

These are the backends' functions that are passed to vc-call-backend in
the mapcar in vc-responsible-backend and the output of
vc-find-backend-function.

1) Are so many samples 4548 seems a very high number for only 25 opened
buffers.

These two numbers are unrelated.  4548 is the number of time the
profiler found the program counter inside project-try-vc and the
functions it calls.  This number has no relation to the number of
buffers you have, it just means that code runs slowly.

Ok

2) why project-try-vc still takes so much...? Specially for unfrequent
vc systems in our days like svn or bzr that I am not using.

That was explained on emacs-devel.  However, ...

As a workaround I removed all the uninteresting handlers from
vc-handled-backends and I get better times now, but IMHO it is still
very inefficient (almost a minute for project-switch-to-buffer is
excessive). And make it practically unusable.

... after removing the "unused" VC back-ends, you say that the code
still runs very slowly.  So is the issue with VC back-ends still
relevant, and if so, how?

Yes, it is. It is still slow, lets say around 20-40 seconds to complete
the command. But that's that's much faster than before (3-5 minutes);
but still too slow to make the command usable.

More importantly, what is the profile after you remove the extra VC
calls?

         790  83% - command-execute
         631  66%  - byte-code
         631  66%   - project--read-project-buffer
         436  46%    + ivy-completing-read
         188  19%    - project-current
         188  19%     - project--find-in-directory
         188  19%      - project-try-vc
         135  14%       - vc-responsible-backend
         135  14%        - #<compiled -0x11223b7c225fdde9>
         135  14%         - vc-call-backend
         135  14%          - apply
         105  11%           - vc-hg-responsible-p
         105  11%            - vc-find-root
         102  10%             - locate-dominating-file
          76   8%              + tramp-file-name-handler
          26   2%              + abbreviate-file-name
          30   3%           - vc-git-responsible-p
          30   3%            - vc-find-root
          30   3%             - locate-dominating-file
          30   3%              + tramp-file-name-handler
          41   4%       - project--vc-merge-submodules-p
          41   4%        - project--value-in-dir
          41   4%         - hack-dir-local-variables-non-file-buffer
          41   4%          - hack-dir-local-variables
          37   3%           - dir-locals-find-file
          27   2%            - locate-dominating-file
          21   2%             + abbreviate-file-name
           6   0%             + dir-locals--all-files
          10   1%            + dir-locals--all-files
          12   1%       + vc-call-backend
           7   0%    + #<compiled 0x34145703cd88c72>


Only with git and mercurial backends and with 10 remote buffers open (in
the first profile there were like 25). Remember that the times grow
linearly with the number of buffers.

As a note here, when N files are in the same directory the normal thing
is that all of them share the VCS. So calling a check function for all
of them is redundant and slow.

VCS changing is not something that happens very often to require a check
of all the backends everytime, several times for every buffer in many
project.el functions right? Specially when using tramp.

Once again, given what you say above, this doesn't sound important,
does it?  The slow processing is elsewhere, and without seeing a
profile with VC calls removed, it's hard to make progress in this
matter, or give you some advice regarding potential reason(s).


Reducing 3-5 minutes to 20-40 seconds when there is only hg and git
sounds relevant for me. Still slow for a command, but important
considering that it is still asking the filesystem for every
file/buffer.

vc has vc-file-prop-obarray; maybe vc-responsible-backend should cache
it's result there to avoid repeating time consuming computations?

Again: is this issue relevant, given that without the VC calls the
code is still very slow?





reply via email to

[Prev in Thread] Current Thread [Next in Thread]