From mboxrd@z Thu Jan 1 00:00:00 1970 Path: news.gmane.io!.POSTED.blaine.gmane.org!not-for-mail From: Ergus via "Bug reports for GNU Emacs, the Swiss army knife of text editors" Newsgroups: gmane.emacs.bugs Subject: bug#49264: 28.0.50; project.el+tramp performance issue Date: Wed, 30 Jun 2021 00:21:42 +0200 Message-ID: <20210629222142.jbyegdo72wkp6vv2@Ergus> References: <87fsx13aiz.fsf.ref@aol.com> <87fsx13aiz.fsf@aol.com> <83mtr8ooz4.fsf@gnu.org> Reply-To: Ergus Mime-Version: 1.0 Content-Type: text/plain; charset=us-ascii; format=flowed Injection-Info: ciao.gmane.io; posting-host="blaine.gmane.org:116.202.254.214"; logging-data="36839"; mail-complaints-to="usenet@ciao.gmane.io" Cc: 49264@debbugs.gnu.org To: Eli Zaretskii Original-X-From: bug-gnu-emacs-bounces+geb-bug-gnu-emacs=m.gmane-mx.org@gnu.org Wed Jun 30 00:23:12 2021 Return-path: Envelope-to: geb-bug-gnu-emacs@m.gmane-mx.org Original-Received: from lists.gnu.org ([209.51.188.17]) by ciao.gmane.io with esmtps (TLS1.2:ECDHE_RSA_AES_256_GCM_SHA384:256) (Exim 4.92) (envelope-from ) id 1lyM8O-0009Ni-4K for geb-bug-gnu-emacs@m.gmane-mx.org; Wed, 30 Jun 2021 00:23:12 +0200 Original-Received: from localhost ([::1]:39284 helo=lists1p.gnu.org) by lists.gnu.org with esmtp (Exim 4.90_1) (envelope-from ) id 1lyM8N-00083U-6G for geb-bug-gnu-emacs@m.gmane-mx.org; Tue, 29 Jun 2021 18:23:11 -0400 Original-Received: from eggs.gnu.org ([2001:470:142:3::10]:46570) by lists.gnu.org with esmtps (TLS1.2:ECDHE_RSA_AES_256_GCM_SHA384:256) (Exim 4.90_1) (envelope-from ) id 1lyM8E-0007zD-Gn for bug-gnu-emacs@gnu.org; Tue, 29 Jun 2021 18:23:02 -0400 Original-Received: from debbugs.gnu.org ([209.51.188.43]:44326) by eggs.gnu.org with esmtps (TLS1.2:ECDHE_RSA_AES_128_GCM_SHA256:128) (Exim 4.90_1) (envelope-from ) id 1lyM8E-0006ea-8z for bug-gnu-emacs@gnu.org; Tue, 29 Jun 2021 18:23:02 -0400 Original-Received: from Debian-debbugs by debbugs.gnu.org with local (Exim 4.84_2) (envelope-from ) id 1lyM8D-00047O-TZ for bug-gnu-emacs@gnu.org; Tue, 29 Jun 2021 18:23:01 -0400 X-Loop: help-debbugs@gnu.org Resent-From: Ergus Original-Sender: "Debbugs-submit" Resent-CC: bug-gnu-emacs@gnu.org Resent-Date: Tue, 29 Jun 2021 22:23:01 +0000 Resent-Message-ID: Resent-Sender: help-debbugs@gnu.org X-GNU-PR-Message: followup 49264 X-GNU-PR-Package: emacs Original-Received: via spool by 49264-submit@debbugs.gnu.org id=B49264.162500532415749 (code B ref 49264); Tue, 29 Jun 2021 22:23:01 +0000 Original-Received: (at 49264) by debbugs.gnu.org; 29 Jun 2021 22:22:04 +0000 Original-Received: from localhost ([127.0.0.1]:55872 helo=debbugs.gnu.org) by debbugs.gnu.org with esmtp (Exim 4.84_2) (envelope-from ) id 1lyM7H-00045x-D8 for submit@debbugs.gnu.org; Tue, 29 Jun 2021 18:22:03 -0400 Original-Received: from sonic302-3.consmr.mail.bf2.yahoo.com ([74.6.135.42]:45451) by debbugs.gnu.org with esmtp (Exim 4.84_2) (envelope-from ) id 1lyM7G-00045T-DK for 49264@debbugs.gnu.org; Tue, 29 Jun 2021 18:22:02 -0400 DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=aol.com; s=a2048; t=1625005316; bh=yzt3sAygmvlmvZYsmxoNHLcVJ9Fu7PIIfrhAMJeryH0=; h=Date:From:To:Cc:Subject:References:In-Reply-To:From:Subject:Reply-To; b=UY7ITrCueIzz8qg33W8vpBnNBwRr8N3Z/p8Qvs/y28gtWeQ/ZBNxsqKsQE2KSWS+9zfxmS97aJCfR8sy8lmARlnehpG3NmiiYJQubS4O96W+oUq6Yeih9JknTe3e90WDAf5sKOOVQ5KgAWnwHCDvpZHD8XV0DcvoQRgLbIAVuyRy9qX9xauJmEyl1rvphOAQA5SHyVuYvG2NSQgAorjdmFPFvWdj/H4X/r6Rfwlb3ivRt/lQchbQ49um6mWmGISGUenjL3LJ1ceaSMqO+1PcAgVnmw/mgU41Cx0cXG49Di7i7ul4iHBG2cYplruyyQCMo0yJYqjEQzqjtINpBuRdOQ== X-SONIC-DKIM-SIGN: v=1; a=rsa-sha256; c=relaxed/relaxed; d=yahoo.com; s=s2048; t=1625005316; bh=XpwTwltnenT/PdFMocFu4PJL8L8diMDe6nuxVqavA9X=; h=X-Sonic-MF:Date:From:To:Subject:From:Subject; b=ZOCjtfxKgmaBogHzJt63wiU1l3+T8ObHmw0MzOadQRi4e2Is2STQXynYba2BvLy2Ds/5crkeBydEaiq929ruzssCFsOa/A9omBAp5NkmlI5ku90AgEuuo0gQU/4uXDFL/wpnAHehsiCWO4ucrAeUrZxYzoSba56R8J772xnEdTvjlG1BeQNk6dsqW87DZ1uCyLyTY84BTJInFS3aIHw9Y8o5ipNCwAI8aw/nVNP9FCHmQZxZ3D/S66fUfMz/1ASorZ8NtTAOZAcBHF5vAd5z+7urSqsFUePrai/+7eqxb4NHVv6KebjnqiVwkcn+1OPhrsBivb+TWDIx6X43DRSw9g== X-YMail-OSG: vPZbcjoVM1m2.KE4s5Ig14Vg6CVVy3gVoxo2doiORuOBmke4_42uQLA7gL9fp3e Qg.2NJgZjNtTBsLVQsC0Lvr0a94GJ2o3mYMqQVplbbjiQeBKstMwDBYbKdCCt_mPzxSFqJrIpiJN LJm5BGyv6PD3Kl2tW8DbcI0I4CmI6n3FCVGnLGL7zBJ0MS19ZxlywvyG4Ph8TQhhpeFpepZhWeAp ZdtpN6F0CFwFVj9Gx0MrEWz8fBpummRBp7wK5gQaPcNBJ_nQKReSCbObn9l4LRyvXRAsWYw.uTDi hvIjFT8gHF3iHN5IRlT.oQ7Aj.IsDSLv0KeHqB3zLcgF2WBwwcJ96KvxuCBwfjZhptfBhaFTJaW9 DgKlF0qTv_cPb.aAb64Qw8MxzjNl9zgrR0qwTZ4dgg3AaCJNgv_HFUgpWFxz92lTY3qrREWETJ3J eruEWwxT61FGEU_T2lQUJLDTjFxh4EuGoQw3vwyeyx4niymNTmtaMMY7sSXaucZ5OaZV5lOt1Fy6 RGwsL99lONBc75Mbu4PEt6OAuGEgoEVzplUVDtuhad7En27Y5DrKA7iYTUqKomRLTez5.71nV0lM YKv8N6lp13Sa8XSR67NOslbcg2IuVrnkb4iRv.r68JVNy1WC0sFcjgs5WUx7t63gVjbMd.Y26ia6 6FNpmEtJmPDrT_WDQIMY3Os9T_I45dY6pAYE6MaDOtyh2jfYWOsFIGYS06TWFOkeVO.7.YFB0JTT 0tTRuCmButK3q1A.PLXzCbZ3jduTEdGoGNoclqe7OaNM067wiv3UL682zJ1E0FSJDrZUUKKX14_u Yl_OLffU.6CaYwOlef6CnRTaGCy7pILQ_yEtf8Nxp0 X-Sonic-MF: Original-Received: from sonic.gate.mail.ne1.yahoo.com by sonic302.consmr.mail.bf2.yahoo.com with HTTP; Tue, 29 Jun 2021 22:21:56 +0000 Original-Received: by kubenode525.mail-prod1.omega.ir2.yahoo.com (VZM Hermes SMTP Server) with ESMTPA ID 462f400b8bb535964166e44dab381a4a; Tue, 29 Jun 2021 22:21:52 +0000 (UTC) Content-Disposition: inline In-Reply-To: <83mtr8ooz4.fsf@gnu.org> X-Mailer: WebService/1.1.18469 mail.backend.jedi.jws.acl:role.jedi.acl.token.atz.jws.hermes.aol X-BeenThere: debbugs-submit@debbugs.gnu.org X-Mailman-Version: 2.1.18 Precedence: list X-BeenThere: bug-gnu-emacs@gnu.org List-Id: "Bug reports for GNU Emacs, the Swiss army knife of text editors" List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , Errors-To: bug-gnu-emacs-bounces+geb-bug-gnu-emacs=m.gmane-mx.org@gnu.org Original-Sender: "bug-gnu-emacs" Xref: news.gmane.io gmane.emacs.bugs:209128 Archived-At: 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" >> >> 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% - # >> 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% - # >> 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% - # 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% + # 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?