Subject: bug#30807: Tramp tests take waaayyy too long and refuse to exit

From: Michael Albinus <[email-masked]>
Date: Wed, 14 Mar 2018 10:07:41 +0100

Paul Eggert <[email-masked]> writes:

Hi Paul,

> For the past few weeks "make check" has been taking a looooong time on
> Emacs master on my Fedora 27 desktop (AMD Phenom II X4 910e).

All following timings are performed on my 8-years old ThinkPad T500 (Intel
Core2 Duo T9550, 4MB RAM).

Yes, something is wrong. In the emacs-26 branch, I see

--8<---------------cut here---------------start------------->8---
$ time make -C test tramp-tests SELECTOR='$(SELECTOR_DEFAULT)'
28.902u 4.947s 0:36.09 93.7%	0+0k 4448+4568io 0pf+0w
--8<---------------cut here---------------end--------------->8---

The same call in master yields

--8<---------------cut here---------------start------------->8---
$ time make -C test tramp-tests SELECTOR='$(SELECTOR_DEFAULT)'
228.608u 7.401s 4:08.63 94.9%	0+0k 8064+8784io 8pf+0w
--8<---------------cut here---------------end--------------->8---

Up to eight time slower. I will check what's up. (Usually, I run only
the expensive Tramp tests, so I haven't seen this yet)

> and some of the tests in the corresponding script look to be very
> slow. Can this be sped up? Let's mark the slow tests to be expensive,
> so that they are run only if one executes "make check-expensive".

This is already the case. I guess you've uncovered an error, which must
be fixed.

> Worse, there's another long wait here:
>
>   GEN      lisp/net/tramp-archive-tests.log
>
> after this line is output:
>
>    passed  20/22  tramp-archive-test40-file-system-info

I don't see an error here. I get

--8<---------------cut here---------------start------------->8---
$ time make -C test tramp-archive-tests SELECTOR='$(SELECTOR_DEFAULT)'
11.131u 0.678s 0:17.43 67.6%	0+0k 0+104io 0pf+0w
--8<---------------cut here---------------end--------------->8---

This is not superfast (17s duration), but maybe acceptable.

> and here the wait is so long that I gave up trying to run the tests
> and typed control-C to exit them. Presumably the semi-inflooping test
> is tramp-archive-test42-auto-load. (Why is it 42 and not 41? Why are
> there two test42s? I don't know.)

No problem here:

--8<---------------cut here---------------start------------->8---
$ time make -C test tramp-archive-tests SELECTOR='\"tramp-archive-test42-auto-load\"'
1.505u 0.256s 0:02.64 66.2%	0+0k 0+0io 0pf+0w
--8<---------------cut here---------------end--------------->8---

The reasoning for the test numbering is explained in the comment of
tramp-archive-tests.el:

;; The `tramp-archive-testnn-*' tests correspond to the respective
;; tests in tramp-tests.el.

> Worse yet, after I control-C out of "make check" and get a shell
> prompt back, a subsidiary Emacs that is running the Tramp test refuses
> to exit and continues to chew up CPU time in the background until I
> use "kill 3304" (or whatever) to kill it. This really needs to get
> fixed.

I will try to produce some instrumentation for tramp-archive-test42-auto-load
in order to catch your problem.

> Because of these problems I no longer routinely run "make check".

This is bad, and we shall fix it.

Best regards, Michael.