GNU bug report logs - #28227
26.0.50; Tramp tests are slow

Previous Next

To add a comment to this bug, you must first unarchive it, by sending
a message to control AT debbugs.gnu.org, with unarchive 28227 in the body.
You can then email your comments to 28227 AT debbugs.gnu.org in the normal way.

Toggle the display of automated, internal messages from the tracker.

Message #5 received at submit <at> debbugs.gnu.org (full text, mbox):

From: Gemini Lasswell <gazally <at> runbox.com>
To: bug-gnu-emacs <at> gnu.org
Subject: 26.0.50; Tramp tests are slow
Date: Thu, 24 Aug 2017 14:03:32 -0700

[Message part 1 (text/plain, inline)]

The Tramp tests are the slowest tests in Emacs's test suite, even when
they aren't set up to access a remote machine.

After a little investigation I think the cause of the slowness is
excessive memory allocation. I modified ert-run-tests to print
memory statistics after each test and found that tramp-tests.el, which
takes 100 seconds to run on my machine, is spending 39 seconds doing
garbage collection, and by the end of the test run has allocated and
freed 27 million strings.

Here is a log file with memory statistics:

[tramp-tests.log (text/plain, attachment)]

[Message part 3 (text/plain, inline)]

And here are the messages I added to ert-run-test's loop:

(message "GC: %s" (garbage-collect))
(message "GC count: %s time: %s" gcs-done gc-elapsed)
(message "Memory-use-counts: %s" (memory-use-counts))

Message #8 received at 28227 <at> debbugs.gnu.org (full text, mbox):

From: Michael Albinus <michael.albinus <at> gmx.de>
To: Gemini Lasswell <gazally <at> runbox.com>
Cc: 28227 <at> debbugs.gnu.org
Subject: Re: bug#28227: 26.0.50; Tramp tests are slow
Date: Fri, 25 Aug 2017 10:04:24 +0200

Gemini Lasswell <gazally <at> runbox.com> writes:

Hi Gemini,

> The Tramp tests are the slowest tests in Emacs's test suite, even when
> they aren't set up to access a remote machine.

Tramp tests are expensive, by design. For example, at the beginning of
every single test the Tramp connection is cleared, including cache
cleanup. 55 tests, this takes time to reestablish the
connection. Furthermore, for all remote process related tests there are
timeouts in order to receive proper response.

Therefore, in the normal "make check" run of Emacs, some of Tramp tests
are skipped.

If you start "make -C test tramp-tests", all Tramp tests run, which
lasts 3:17 min on my laptop (Lenovo T500, 7 years old). You could
restrict this to the non-expensive tests by calling "make
SELECTOR='$(SELECTOR_DEFAULT)' -C test tramp-tests". This reduces the
runtime to 34 sec on my laptop. See test/README for explanation.

For normal use, the non-expensive Tramp tests are sufficient.

> After a little investigation I think the cause of the slowness is
> excessive memory allocation. I modified ert-run-tests to print
> memory statistics after each test and found that tramp-tests.el, which
> takes 100 seconds to run on my machine, is spending 39 seconds doing
> garbage collection, and by the end of the test run has allocated and
> freed 27 million strings.
>
> Here is a log file with memory statistics:
>
> And here are the messages I added to ert-run-test's loop:
>
> (message "GC: %s" (garbage-collect))
> (message "GC count: %s time: %s" gcs-done gc-elapsed)
> (message "Memory-use-counts: %s" (memory-use-counts))

Thanks for this. My experience with Tramp is, that most of the time is
spent in process communication.

Anyway, I'll see, whether I could optimize Tramp somehow, but
functionality comes first.

Best regards, Michael.

Message #11 received at 28227 <at> debbugs.gnu.org (full text, mbox):

From: Gemini Lasswell <gazally <at> runbox.com>
To: Michael Albinus <michael.albinus <at> gmx.de>
Cc: 28227 <at> debbugs.gnu.org
Subject: Re: bug#28227: 26.0.50; Tramp tests are slow
Date: Wed, 30 Aug 2017 18:20:08 -0700

[Message part 1 (text/plain, inline)]

Hi Michael,

Thank you for the test running tips. The reason I noticed that the Tramp
tests were an outlier in terms of time to execute was not that I was
running the entire set of Tramp tests. My pet project is getting as much
as possible of Emacs and its tests to run with Edebug/Testcover code
coverage turned on in order to generate code coverage reports. The
volume of data structures created for code coverage cause garbage
collection to be expensive. Everything runs slower with code coverage
on, but expensive garbage collection makes even the "make check" set of
Tramp tests run extremely slowly.

Looking at the code coverage reports gave me some insight into why Tramp
does so much garbage collection. tramp-file-name-structure gets called
over 2 million times during the full run of Tramp tests, and creates
strings and builds a list each time, but only constructs one of three
possible results depending on the value of tramp-syntax. The result
lists are not modified by the code they are returned to.

In the attached patch I have modified tramp-file-name-structure and its
subroutines so that the three results are calculated once and then
looked up when needed. With this patch the full set of Tramp tests takes
1/3 as long to complete as before.

It's not my use case, but it seems possible that this patch would be a
noticable performance improvement to someone who keeps a long running
Emacs process with lots of data loaded (hence costly garbage collection)
and also uses Tramp heavily over fast network connections.

Besides the patch I'm attaching two coverage reports which you may find
interesting. The code coverage data were created by running the full
set of Tramp tests, one without the patch and one with the patch. The
reports were generated with genhtml from a lcov info file written by a
modified version of Testcover which collects execution counts. The
number between the line number and the code on each line is the maximum
of the execution counts of the forms in that line of code.

Best regards,
Gemini

[0001-Reduce-Tramp-s-memory-usage.patch (text/plain, attachment)]

[coverage-report-before.tar.gz (application/octet-stream, attachment)]

[coverage-report.tar.gz (application/octet-stream, attachment)]

Message #14 received at 28227 <at> debbugs.gnu.org (full text, mbox):

From: npostavs <at> users.sourceforge.net
To: Gemini Lasswell <gazally <at> runbox.com>
Cc: Michael Albinus <michael.albinus <at> gmx.de>, 28227 <at> debbugs.gnu.org
Subject: Re: bug#28227: 26.0.50; Tramp tests are slow
Date: Wed, 30 Aug 2017 22:26:33 -0400

Gemini Lasswell <gazally <at> runbox.com> writes:

> +(defmacro tramp-lookup-syntax (alist)
> +  "Look up a syntax string in ALIST according to `tramp-compat-tramp-syntax.'
> +Raise an error if `tramp-syntax' is invalid."
> +  `(let ((result (cdr (assq (tramp-compat-tramp-syntax) ,alist))))
> +     (or result
> +         (error "Wrong `tramp-syntax' %s" tramp-syntax))))

Was there a reason to defmacro instead of defun here?  If it's
performance, perhaps defsubst could work instead?

(also, the let-binding seems redundant)

Message #17 received at 28227 <at> debbugs.gnu.org (full text, mbox):

From: Gemini Lasswell <gazally <at> runbox.com>
To: npostavs <at> users.sourceforge.net
Cc: Michael Albinus <michael.albinus <at> gmx.de>, 28227 <at> debbugs.gnu.org
Subject: Re: bug#28227: 26.0.50; Tramp tests are slow
Date: Thu, 31 Aug 2017 07:46:33 -0700

[Message part 1 (text/plain, inline)]

Here's a new patch which uses defun and doesn't have the let binding.
Performance is not noticably different.

[0001-Reduce-Tramp-s-memory-usage.patch (text/plain, attachment)]

[Message part 3 (text/plain, inline)]

npostavs <at> users.sourceforge.net writes:

> Gemini Lasswell <gazally <at> runbox.com> writes:
>
>> +(defmacro tramp-lookup-syntax (alist)
>> +  "Look up a syntax string in ALIST according to `tramp-compat-tramp-syntax.'
>> +Raise an error if `tramp-syntax' is invalid."
>> +  `(let ((result (cdr (assq (tramp-compat-tramp-syntax) ,alist))))
>> +     (or result
>> +         (error "Wrong `tramp-syntax' %s" tramp-syntax))))
>
> Was there a reason to defmacro instead of defun here?  If it's
> performance, perhaps defsubst could work instead?
>
> (also, the let-binding seems redundant)

Message #20 received at 28227 <at> debbugs.gnu.org (full text, mbox):

From: Michael Albinus <michael.albinus <at> gmx.de>
To: Gemini Lasswell <gazally <at> runbox.com>
Cc: 28227 <at> debbugs.gnu.org, npostavs <at> users.sourceforge.net
Subject: Re: bug#28227: 26.0.50; Tramp tests are slow
Date: Fri, 01 Sep 2017 14:28:33 +0200

Gemini Lasswell <gazally <at> runbox.com> writes:

Hi Gemini,

> Here's a new patch which uses defun and doesn't have the let binding.
> Performance is not noticably different.

Looks good to me, thanks a lot! You could apply this to master.

`tramp-prefix-method-regexp-alist' might be renamed to
`tramp-method-regexp-alist'.

And `tramp-*-regexp-alist' might be derived from `tramp-*-format-alist',
as the docstring says. Otherwise, you would use the same string literals
twice, which is always good for errors during maintenance. Something like

(defconst tramp-prefix-regexp-alist
  (mapcar (lambda (x) (cons (car x) (concat "^" (regexp-quote (cdr x)))))
          tramp-prefix-format-alist)
  "Alist of regexps matching the beginnings of Tramp file names.
Keyed by Tramp syntax. Derived from `tramp-prefix-format-alist'.")

Best regards, Michael.

Message #23 received at 28227 <at> debbugs.gnu.org (full text, mbox):

From: Gemini Lasswell <gazally <at> runbox.com>
To: Michael Albinus <michael.albinus <at> gmx.de>
Cc: 28227 <at> debbugs.gnu.org, npostavs <at> users.sourceforge.net
Subject: Re: bug#28227: 26.0.50; Tramp tests are slow
Date: Mon, 04 Sep 2017 15:43:17 -0700

[Message part 1 (text/plain, inline)]

Michael Albinus writes:
> Looks good to me, thanks a lot! You could apply this to master.

Hi Michael,
Here's a new version of the patch which incorporates your suggestions:

[0001-Reduce-Tramp-s-memory-usage.patch (text/plain, attachment)]

[Message part 3 (text/plain, inline)]

I submitted a request for write permissions this weekend, so I'll push
it after I hear back about that, if there's no other feedback.
Best,
Gemini

Message #26 received at 28227 <at> debbugs.gnu.org (full text, mbox):

From: Michael Albinus <michael.albinus <at> gmx.de>
To: Gemini Lasswell <gazally <at> runbox.com>
Cc: 28227 <at> debbugs.gnu.org, npostavs <at> users.sourceforge.net
Subject: Re: bug#28227: 26.0.50; Tramp tests are slow
Date: Tue, 05 Sep 2017 09:45:09 +0200

Gemini Lasswell <gazally <at> runbox.com> writes:

> Hi Michael,

Hi Gemini,

> Here's a new version of the patch which incorporates your suggestions:

LGTM, thanks!

> I submitted a request for write permissions this weekend, so I'll push
> it after I hear back about that, if there's no other feedback.
>
> Best,
> Gemini

Best regards, Michael.

Message #31 received at 28227-done <at> debbugs.gnu.org (full text, mbox):

From: Gemini Lasswell <gazally <at> runbox.com>
To: 28227-done <at> debbugs.gnu.org
Cc: Michael Albinus <michael.albinus <at> gmx.de>, npostavs <at> users.sourceforge.net
Subject: Re: bug#28227: 26.0.50; Tramp tests are slow
Date: Sat, 09 Sep 2017 09:27:25 -0700

Michael Albinus writes:

> Gemini Lasswell <gazally <at> runbox.com> writes:
>> Here's a new version of the patch which incorporates your suggestions:
>
> LGTM, thanks!

Pushed to master.

Message #34 received at 28227 <at> debbugs.gnu.org (full text, mbox):

From: Michael Albinus <michael.albinus <at> gmx.de>
To: Gemini Lasswell <gazally <at> runbox.com>
Cc: 28227 <at> debbugs.gnu.org, npostavs <at> users.sourceforge.net
Subject: Re: bug#28227: 26.0.50; Tramp tests are slow
Date: Sat, 09 Sep 2017 19:47:17 +0200

Gemini Lasswell <gazally <at> runbox.com> writes:

> Pushed to master.

Thanks!

Best regards, Michael.

Previous Next

GNU bug tracking system
Copyright (C) 1999 Darren O. Benham, 1997,2003 nCipher Corporation Ltd, 1994-97 Ian Jackson.