bug#36940: tests slowness and failure after recent Tramp changes

bug#36940: tests slowness and failure after recent Tramp changes

[Paul Eggert]

[-- Attachment #1: Type: text/plain, Size: 516 bytes --]

I'm having trouble with 'make check' after the recent Tramp changes on master. 
First, the Tramp tests are now too slow; they take over 6 minutes on my platform 
(Fedora 30 x86-4, AMD Phenom II X4 910e, default optimization), which is so slow 
that I don't want to run 'make check' while developing, which would be a bad 
habit to get into.

Second, the tramp-test19-directory-files-and-attributes test now fails.

A nit: the output has some weird spacing and log lines.

Attached is a log illustrating the problem.

[-- Attachment #2: tramp-log.txt --]
[-- Type: text/plain, Size: 7704 bytes --]

$ cd test
$ make lisp/net/tramp-tests
make[1]: Entering directory '/home/eggert/src/gnu/emacs/static-checking/test'
  ELC      lisp/net/tramp-tests.elc
  GEN      lisp/net/tramp-tests.log
Running 67 tests (2019-08-05 17:14:55-0700, selector `(not (tag :unstable))')
Remote directory: `/mock::/tmp/'
   passed   1/67  tramp-test00-availability (0.134091 sec)
   passed   2/67  tramp-test01-file-name-syntax (0.000661 sec)
   passed   3/67  tramp-test01-file-name-syntax-separate (0.057887 sec)
   passed   4/67  tramp-test01-file-name-syntax-simplified (0.000537 sec)
   passed   5/67  tramp-test02-file-name-dissect (0.164562 sec)
   passed   6/67  tramp-test02-file-name-dissect-separate (0.182987 sec)
   passed   7/67  tramp-test02-file-name-dissect-simplified (0.125639 sec)
   passed   8/67  tramp-test03-file-name-defaults (0.047693 sec)
   passed   9/67  tramp-test03-file-name-host-rules (0.047958 sec)
   passed  10/67  tramp-test03-file-name-method-rules (0.000560 sec)
   passed  11/67  tramp-test04-substitute-in-file-name (0.046616 sec)
   passed  12/67  tramp-test05-expand-file-name (0.002662 sec)
   failed  13/67  tramp-test05-expand-file-name-relative (0.109334 sec)
   passed  14/67  tramp-test06-directory-file-name (0.008505 sec)
   passed  15/67  tramp-test07-file-exists-p (0.292224 sec)
   passed  16/67  tramp-test08-file-local-copy (0.572839 sec)
   passed  17/67  tramp-test09-insert-file-contents (0.788645 sec)
Wrote /mock:Penguin.CS.UCLA.EDU:/tmp/tramp-testKPOCQh
Wrote /mock:Penguin.CS.UCLA.EDU:/tmp/tramp-testKPOCQh
Wrote /mock:Penguin.CS.UCLA.EDU:/tmp/tramp-testKPOCQh
Wrote /mock:Penguin.CS.UCLA.EDU:/:/tmp/tramp-testVgUm8p
Wrote /mock:Penguin.CS.UCLA.EDU:/:/tmp/tramp-testVgUm8p
Wrote /mock:Penguin.CS.UCLA.EDU:/:/tmp/tramp-testVgUm8p
   passed  18/67  tramp-test10-write-region (2.489417 sec)


   passed  19/67  tramp-test10-write-region-file-precious-flag (0.909157 sec)
   passed  20/67  tramp-test11-copy-file (4.763587 sec)
   passed  21/67  tramp-test12-rename-file (5.399255 sec)
   passed  22/67  tramp-test13-make-directory (0.285463 sec)
   passed  23/67  tramp-test14-delete-directory (0.408382 sec)
   passed  24/67  tramp-test15-copy-directory (2.118540 sec)
   passed  25/67  tramp-test16-directory-files (0.551886 sec)
   passed  26/67  tramp-test16-file-expand-wildcards (0.863207 sec)
   passed  27/67  tramp-test17-dired-with-wildcards (1.344551 sec)
   passed  28/67  tramp-test17-insert-directory (0.770590 sec)
   passed  29/67  tramp-test18-file-attributes (0.913425 sec)
Test tramp-test19-directory-files-and-attributes backtrace:
  signal(ert-test-failed (((should (tramp--test-file-attributes-equal-
  ert-fail(((should (tramp--test-file-attributes-equal-p (file-attribu
  (if (unwind-protect (setq value-4208 (apply fn-4206 args-4207)) (set
  (let (form-description-4210) (if (unwind-protect (setq value-4208 (a
  (let ((value-4208 'ert-form-evaluation-aborted-4209)) (let (form-des
  (let* ((fn-4206 #'tramp--test-file-attributes-equal-p) (args-4207 (c
  (if (tramp-compat-time-equal-p (nth 5 (file-attributes (expand-file-
  (let ((elt (car --dolist-tail--))) (if (tramp-compat-time-equal-p (n
  (while --dolist-tail-- (let ((elt (car --dolist-tail--))) (if (tramp
  (let ((--dolist-tail-- attr)) (while --dolist-tail-- (let ((elt (car
  (progn (make-directory tmp-name1) (let* ((fn-4191 #'file-directory-p
  (unwind-protect (progn (make-directory tmp-name1) (let* ((fn-4191 #'
  (let* ((tmp-name1 (tramp--test-make-temp-name nil quoted)) (tmp-name
  (let ((quoted (car --dolist-tail--))) (let* ((tmp-name1 (tramp--test
  (while --dolist-tail-- (let ((quoted (car --dolist-tail--))) (let* (
  (let ((--dolist-tail-- (if (tramp--test-expensive-test) '(nil t) '(n
  (closure (t) nil (let* ((fn-4186 #'tramp--test-enabled) (args-4187 (
  ert--run-test-internal(#s(ert--test-execution-info :test #s(ert-test
  ert-run-test(#s(ert-test :name tramp-test19-directory-files-and-attr
  ert-run-or-rerun-test(#s(ert--stats :selector (not ...) :tests [...
  ert-run-tests((not (tag :unstable)) #f(compiled-function (event-type
  ert-run-tests-batch((not (tag :unstable)))
  ert-run-tests-batch-and-exit((not (tag :unstable)))
  eval((ert-run-tests-batch-and-exit '(not (tag :unstable))) t)
  command-line-1(("-L" ":." "-l" "ert" "-l" "lisp/net/tramp-tests.el"
  command-line()
  normal-top-level()
Test tramp-test19-directory-files-and-attributes condition:
    (ert-test-failed
     ((should
       (tramp--test-file-attributes-equal-p
	(file-attributes ...)
	(cdr elt)))
      :form
      (tramp--test-file-attributes-equal-p
       (t 2 1000 1000
	  (0 0 0 1000)
	  (0 0 0 1000)
	  (0 0 0 1000)
	  60 "drwxrwxr-x" nil ...)
       (t 2 1000 1000
	  (0 0 0 1000)
	  (0 0 0 1000)
	  (0 0 0 1000)
	  100 "drwxrwxr-x" nil ...))
      :value nil :explanation
      (list-elt 7
		(different-atoms
		 (60 "#x3c" "?<")
		 (100 "#x64" "?d")))))
   FAILED  30/67  tramp-test19-directory-files-and-attributes (0.395179 sec)
   passed  31/67  tramp-test20-file-modes (0.494030 sec)
   passed  32/67  tramp-test21-file-links (3.496317 sec)
   passed  33/67  tramp-test22-file-times (0.635292 sec)
   passed  34/67  tramp-test23-visited-file-modtime (0.467235 sec)
   passed  35/67  tramp-test24-file-acl (1.166780 sec)
   passed  36/67  tramp-test25-file-selinux (1.071320 sec)
   passed  37/67  tramp-test26-file-name-completion (1.717422 sec)
   passed  38/67  tramp-test27-load (0.674823 sec)
   passed  39/67  tramp-test28-process-file (0.354999 sec)
   passed  40/67  tramp-test29-start-file-process (0.611865 sec)
   passed  41/67  tramp-test30-make-process (1.050409 sec)
   passed  42/67  tramp-test31-interrupt-process (0.227394 sec)
   passed  43/67  tramp-test32-shell-command (1.585847 sec)
   passed  44/67  tramp-test33-environment-variables (1.115707 sec)
   passed  45/67  tramp-test33-environment-variables-and-port-numbers (0.181967 sec)






   passed  46/67  tramp-test34-connection-local-variables (1.904476 sec)
   passed  47/67  tramp-test34-explicit-shell-file-name (0.245684 sec)
   passed  48/67  tramp-test35-exec-path (0.582164 sec)
   passed  49/67  tramp-test35-remote-path (7.544241 sec)
(Git)
   passed  50/67  tramp-test36-vc-registered (1.141876 sec)
   passed  51/67  tramp-test37-make-auto-save-file-name (0.230174 sec)
   passed  52/67  tramp-test38-find-backup-file-name (0.480164 sec)
   passed  53/67  tramp-test39-make-nearby-temp-file (0.317687 sec)
   passed  54/67  tramp-test40-special-characters (20.833243 sec)
   passed  55/67  tramp-test40-special-characters-with-ls (21.260023 sec)
   passed  56/67  tramp-test40-special-characters-with-perl (25.160176 sec)
   passed  57/67  tramp-test40-special-characters-with-stat (20.912877 sec)
   passed  58/67  tramp-test41-utf8 (62.499158 sec)
   passed  59/67  tramp-test41-utf8-with-ls (60.226228 sec)
   passed  60/67  tramp-test41-utf8-with-perl (69.988970 sec)
   passed  61/67  tramp-test41-utf8-with-stat (61.849094 sec)
   passed  62/67  tramp-test42-file-system-info (0.137832 sec)
   passed  63/67  tramp-test44-auto-load (0.253701 sec)
   passed  64/67  tramp-test44-delay-load (0.326123 sec)
   passed  65/67  tramp-test44-recursive-load (0.488679 sec)
   passed  66/67  tramp-test44-remote-load-path (0.279566 sec)
   passed  67/67  tramp-test45-unload (0.387463 sec)

Ran 67 tests, 66 results as expected, 1 unexpected (2019-08-05 17:21:32-0700, 397.134878 sec)
1 expected failures

1 unexpected results:
   FAILED  tramp-test19-directory-files-and-attributes

make[1]: *** [Makefile:183: lisp/net/tramp-tests.log] Error 1
make[1]: Leaving directory '/home/eggert/src/gnu/emacs/static-checking/test'
make: *** [Makefile:248: lisp/net/tramp-tests] Error 2

bug#36940: tests slowness and failure after recent Tramp changes

[Michael Albinus]

Paul Eggert <eggert@cs.ucla.edu> writes:

Hi Paul,

> I'm having trouble with 'make check' after the recent Tramp changes on
> master. First, the Tramp tests are now too slow; they take over 6
> minutes on my platform (Fedora 30 x86-4, AMD Phenom II X4 910e,
> default optimization), which is so slow that I don't want to run 'make
> check' while developing, which would be a bad habit to get into.

You have run the expensive tests with this call. If you want to run the
default tests, which are active while "make check", you must use the
default selector. See test/README. On my local machine, this makes the
following difference:

$ make tramp-tests
Ran 67 tests, 65 results as expected, 1 unexpected, 1 skipped (2019-08-06 14:45:25+0200, 420.067490 sec)

$ make tramp-tests SELECTOR='$(SELECTOR_DEFAULT)'
Ran 47 tests, 45 results as expected, 1 unexpected, 1 skipped (2019-08-06 14:49:12+0200, 29.771561 sec)

Note, that you don't need the whole path of the test file, its basename
is sufficient.

> Second, the tramp-test19-directory-files-and-attributes test now fails.

Hmm, prior pushing the patch yesterday, all tests have passed. Today, I
can reproduce the problem. Maybe some of the time conversion changes,
arrived over night, have caused this failure? Will check.

> A nit: the output has some weird spacing and log lines.

I know. Its a continued hunt for years to remove these quirks. Some of
them (like the empty lines) are mysterious, and hard to detect where they
come from.

Best regards, Michael.

bug#36940: tests slowness and failure after recent Tramp changes

[Paul Eggert]

Michael Albinus wrote:
>> Second, the tramp-test19-directory-files-and-attributes test now fails.
> Hmm, prior pushing the patch yesterday, all tests have passed. Today, I
> can reproduce the problem. Maybe some of the time conversion changes,
> arrived over night, have caused this failure? Will check.

Thanks for looking into it. The failure started with commit 
2019-08-05T11:09:26Z!michael.albinus@gmx.de 
(6c1d0d53b34d9350d55ebbd83ea56aa751a55f1b), which predates those time-conversion 
changes.

> If you want to run the
> default tests, which are active while "make check", you must use the
> default selector. See test/README.

Thanks, I didn't know that. But that's confusing, as it's natural to assume that 
if FOO is an individual check, then 'make FOO' will run it the same way that 
'make check' would. Would it make sense to change this test to be more natural?

bug#36940: tests slowness and failure after recent Tramp changes

[Michael Albinus]

Paul Eggert <eggert@cs.ucla.edu> writes:

Hi Paul,

>> If you want to run the
>> default tests, which are active while "make check", you must use the
>> default selector. See test/README.
>
> Thanks, I didn't know that. But that's confusing, as it's natural to
> assume that if FOO is an individual check, then 'make FOO' will run it
> the same way that 'make check' would. Would it make sense to change
> this test to be more natural?

It is intended this way. If I call 'make FOO', I'm interested in package
FOO. For example, because I have changed something in FOO, and I want
to know that I didn't break anything. Expensive tests are part of this.

This is the most applied use case of 'make FOO'. At least I call it
several times a week for exactly this reason. That's why we have the
behavior as it is.

All of this has been discussed already, somewhere in the emacs-devel ML
archives.

Best regards, Michael.

bug#36940: tests slowness and failure after recent Tramp changes

[Michael Albinus]

Paul Eggert <eggert@cs.ucla.edu> writes:

>> Hmm, prior pushing the patch yesterday, all tests have passed. Today, I
>> can reproduce the problem. Maybe some of the time conversion changes,
>> arrived over night, have caused this failure? Will check.
>
> Thanks for looking into it. The failure started with commit
> 2019-08-05T11:09:26Z!michael.albinus@gmx.de
> (6c1d0d53b34d9350d55ebbd83ea56aa751a55f1b), which predates those
> time-conversion changes.

I've pushed a patch to master, which ought to fix it. Could you, pls,
check?

It was a problem inside tramp-tests, indeed. My final check yesterday
must have been too sloppy, don't know ... :-(

Best regards, Michael.

bug#36940: tests slowness and failure after recent Tramp changes

[Paul Eggert]

[-- Attachment #1: Type: text/plain, Size: 425 bytes --]

Michael Albinus wrote:
> I've pushed a patch to master, which ought to fix it. Could you, pls,
> check?

Unfortunately I'm still having a problem with that commit 
(998f3612f7e3732d43d8cc6827a16a29008f5db5) on the same platform. Log attached. 
For what it's worth, the test does work for me on another desktop that runs 
Ubuntu 18.04.2, which uses Linux 4.15.0 instead of the Linux 5.1.20 in the 
failing Fedora 30 platform.

[-- Attachment #2: tramp-tests.log --]
[-- Type: text/x-log, Size: 4867 bytes --]

Running 47 tests (2019-08-06 16:22:08-0700, selector `(not (or (tag :expensive-test) (tag :unstable)))')
Remote directory: `/mock::/tmp/'
   passed   1/47  tramp-test00-availability (0.124120 sec)
   passed   2/47  tramp-test01-file-name-syntax (0.000474 sec)
   passed   3/47  tramp-test02-file-name-dissect (0.133566 sec)
   passed   4/47  tramp-test03-file-name-defaults (0.040009 sec)
   passed   5/47  tramp-test03-file-name-host-rules (0.032902 sec)
   passed   6/47  tramp-test03-file-name-method-rules (0.000472 sec)
   passed   7/47  tramp-test04-substitute-in-file-name (0.018056 sec)
   passed   8/47  tramp-test05-expand-file-name (0.021939 sec)
   failed   9/47  tramp-test05-expand-file-name-relative (0.077058 sec)
   passed  10/47  tramp-test06-directory-file-name (0.029155 sec)
   passed  11/47  tramp-test07-file-exists-p (0.209483 sec)
   passed  12/47  tramp-test08-file-local-copy (0.354774 sec)
   passed  13/47  tramp-test09-insert-file-contents (0.443813 sec)
Wrote /mock:Penguin.CS.UCLA.EDU:/tmp/tramp-testjXVD5K
Wrote /mock:Penguin.CS.UCLA.EDU:/tmp/tramp-testjXVD5K
Wrote /mock:Penguin.CS.UCLA.EDU:/tmp/tramp-testjXVD5K
   passed  14/47  tramp-test10-write-region (1.247663 sec)


   passed  15/47  tramp-test10-write-region-file-precious-flag (0.823604 sec)
   passed  16/47  tramp-test11-copy-file (2.175732 sec)
   passed  17/47  tramp-test12-rename-file (2.528836 sec)
   passed  18/47  tramp-test13-make-directory (0.187178 sec)
   passed  19/47  tramp-test14-delete-directory (0.251401 sec)
   passed  20/47  tramp-test15-copy-directory (1.036025 sec)
   passed  21/47  tramp-test16-directory-files (0.327911 sec)
   passed  22/47  tramp-test16-file-expand-wildcards (0.481569 sec)
   passed  23/47  tramp-test17-dired-with-wildcards (0.669597 sec)
   passed  24/47  tramp-test17-insert-directory (0.478189 sec)
   passed  25/47  tramp-test18-file-attributes (0.491410 sec)
Test tramp-test19-directory-files-and-attributes backtrace:
  signal(ert-test-failed (((should (tramp--test-file-attributes-equal-
  ert-fail(((should (tramp--test-file-attributes-equal-p (file-attribu
  #f(compiled-function () #<bytecode 0x759ea5>)()
  ert--run-test-internal(#s(ert--test-execution-info :test #s(ert-test
  ert-run-test(#s(ert-test :name tramp-test19-directory-files-and-attr
  ert-run-or-rerun-test(#s(ert--stats :selector (not ...) :tests [... 
  ert-run-tests((not (or (tag :expensive-test) (tag :unstable))) #f(co
  ert-run-tests-batch((not (or (tag :expensive-test) (tag :unstable)))
  ert-run-tests-batch-and-exit((not (or (tag :expensive-test) (tag :un
  eval((ert-run-tests-batch-and-exit '(not (or (tag :expensive-test) (
  command-line-1(("-L" ":." "-l" "ert" "-l" "lisp/net/tramp-tests" "--
  command-line()
  normal-top-level()
Test tramp-test19-directory-files-and-attributes condition:
    (ert-test-failed
     ((should
       (tramp--test-file-attributes-equal-p
	(file-attributes ...)
	(cdr elt)))
      :form
      (tramp--test-file-attributes-equal-p
       (t 2 1000 1000
	  (0 0 0 1000)
	  (0 0 0 1000)
	  (0 0 0 1000)
	  60 "drwxrwxr-x" nil ...)
       (t 2 1000 1000
	  (0 0 0 1000)
	  (0 0 0 1000)
	  (0 0 0 1000)
	  100 "drwxrwxr-x" nil ...))
      :value nil :explanation
      (list-elt 7
		(different-atoms
		 (60 "#x3c" "?<")
		 (100 "#x64" "?d")))))
   FAILED  26/47  tramp-test19-directory-files-and-attributes (0.369029 sec)
   passed  27/47  tramp-test20-file-modes (0.320524 sec)
   passed  28/47  tramp-test21-file-links (1.356889 sec)
   passed  29/47  tramp-test22-file-times (0.385596 sec)
   passed  30/47  tramp-test23-visited-file-modtime (0.287367 sec)
   passed  31/47  tramp-test24-file-acl (0.637262 sec)
   passed  32/47  tramp-test25-file-selinux (0.600209 sec)
   passed  33/47  tramp-test26-file-name-completion (0.939379 sec)
   passed  34/47  tramp-test27-load (0.405834 sec)
   passed  35/47  tramp-test33-environment-variables-and-port-numbers (0.198027 sec)
   passed  36/47  tramp-test35-exec-path (0.555709 sec)
   passed  37/47  tramp-test35-remote-path (7.146605 sec)
   passed  38/47  tramp-test37-make-auto-save-file-name (0.166199 sec)
   passed  39/47  tramp-test38-find-backup-file-name (0.283166 sec)
   passed  40/47  tramp-test39-make-nearby-temp-file (0.301932 sec)
   passed  41/47  tramp-test40-special-characters (1.293997 sec)
   passed  42/47  tramp-test41-utf8 (3.912456 sec)
   passed  43/47  tramp-test42-file-system-info (0.119547 sec)
   passed  44/47  tramp-test44-auto-load (0.257730 sec)
   passed  45/47  tramp-test44-delay-load (0.326524 sec)
   passed  46/47  tramp-test44-recursive-load (0.483671 sec)
   passed  47/47  tramp-test44-remote-load-path (0.310085 sec)

Ran 47 tests, 46 results as expected, 1 unexpected (2019-08-06 16:22:41-0700, 33.480313 sec)
1 expected failures

1 unexpected results:
   FAILED  tramp-test19-directory-files-and-attributes

bug#36940: tests slowness and failure after recent Tramp changes

[Michael Albinus]

Paul Eggert <eggert@cs.ucla.edu> writes:

Hi Paul,

> Unfortunately I'm still having a problem with that commit
> (998f3612f7e3732d43d8cc6827a16a29008f5db5) on the same platform. Log
> attached. For what it's worth, the test does work for me on another
> desktop that runs Ubuntu 18.04.2, which uses Linux 4.15.0 instead of
> the Linux 5.1.20 in the failing Fedora 30 platform.

My most recent commit has passed the tests on emba. Maybe it works for
you as well?

Best regards, Michael.

bug#36940: tests slowness and failure after recent Tramp changes

[Paul Eggert]

[-- Attachment #1: Type: text/plain, Size: 589 bytes --]

Michael Albinus wrote:

> My most recent commit has passed the tests on emba. Maybe it works for
> you as well?

Thanks, it does fix the failure. However, the test is still quite a bit slower 
for me than you even when I invoke it the way you suggest, as it takes 108 
seconds for me compared to 30 seconds for you. The four slowest tests are:

    passed  37/47  tramp-test35-remote-path (25.712913 sec)
    passed  42/47  tramp-test41-utf8 (14.036743 sec)
    passed  17/47  tramp-test12-rename-file (8.772317 sec)
    passed  16/47  tramp-test11-copy-file (7.754914 sec)

Log attached.

[-- Attachment #2: tramp-tests.log --]
[-- Type: text/x-log, Size: 3633 bytes --]

make tramp-tests SELECTOR='$(SELECTOR_DEFAULT)'
make[1]: Entering directory '/home/eggert/src/gnu/emacs/static-checking/test'
  GEN      lisp/net/tramp-tests.log
Running 47 tests (2019-08-07 12:16:10-0700, selector `(not (or (tag :expensive-test) (tag :unstable)))')
Remote directory: `/mock::/tmp/'
   passed   1/47  tramp-test00-availability (0.447767 sec)
   passed   2/47  tramp-test01-file-name-syntax (0.002684 sec)
   passed   3/47  tramp-test02-file-name-dissect (0.734056 sec)
   passed   4/47  tramp-test03-file-name-defaults (0.191961 sec)
   passed   5/47  tramp-test03-file-name-host-rules (0.175038 sec)
   passed   6/47  tramp-test03-file-name-method-rules (0.002534 sec)
   passed   7/47  tramp-test04-substitute-in-file-name (0.065262 sec)
   passed   8/47  tramp-test05-expand-file-name (0.015119 sec)
   failed   9/47  tramp-test05-expand-file-name-relative (0.299911 sec)
   passed  10/47  tramp-test06-directory-file-name (0.048115 sec)
   passed  11/47  tramp-test07-file-exists-p (0.664484 sec)
   passed  12/47  tramp-test08-file-local-copy (1.094731 sec)
   passed  13/47  tramp-test09-insert-file-contents (1.503054 sec)
Wrote /mock:Penguin.CS.UCLA.EDU:/tmp/tramp-testC7bzT8
Wrote /mock:Penguin.CS.UCLA.EDU:/tmp/tramp-testC7bzT8
Wrote /mock:Penguin.CS.UCLA.EDU:/tmp/tramp-testC7bzT8
   passed  14/47  tramp-test10-write-region (4.388953 sec)


   passed  15/47  tramp-test10-write-region-file-precious-flag (2.844410 sec)
   passed  16/47  tramp-test11-copy-file (7.754914 sec)
   passed  17/47  tramp-test12-rename-file (8.772317 sec)
   passed  18/47  tramp-test13-make-directory (0.573823 sec)
   passed  19/47  tramp-test14-delete-directory (0.743724 sec)
   passed  20/47  tramp-test15-copy-directory (3.543121 sec)
   passed  21/47  tramp-test16-directory-files (1.072810 sec)
   passed  22/47  tramp-test16-file-expand-wildcards (1.547967 sec)
   passed  23/47  tramp-test17-dired-with-wildcards (2.395239 sec)
   passed  24/47  tramp-test17-insert-directory (1.438945 sec)
   passed  25/47  tramp-test18-file-attributes (1.552938 sec)
   passed  26/47  tramp-test19-directory-files-and-attributes (1.411831 sec)
   passed  27/47  tramp-test20-file-modes (0.932448 sec)
   passed  28/47  tramp-test21-file-links (4.446227 sec)
   passed  29/47  tramp-test22-file-times (1.181041 sec)
   passed  30/47  tramp-test23-visited-file-modtime (0.897547 sec)
   passed  31/47  tramp-test24-file-acl (2.017728 sec)
   passed  32/47  tramp-test25-file-selinux (1.899147 sec)
   passed  33/47  tramp-test26-file-name-completion (3.399350 sec)
   passed  34/47  tramp-test27-load (1.290928 sec)
   passed  35/47  tramp-test33-environment-variables-and-port-numbers (0.580866 sec)
   passed  36/47  tramp-test35-exec-path (1.806510 sec)
   passed  37/47  tramp-test35-remote-path (25.712913 sec)
   passed  38/47  tramp-test37-make-auto-save-file-name (0.595497 sec)
   passed  39/47  tramp-test38-find-backup-file-name (0.877389 sec)
   passed  40/47  tramp-test39-make-nearby-temp-file (0.968422 sec)
   passed  41/47  tramp-test40-special-characters (4.483880 sec)
   passed  42/47  tramp-test41-utf8 (14.036743 sec)
   passed  43/47  tramp-test42-file-system-info (0.380808 sec)
   passed  44/47  tramp-test44-auto-load (0.917644 sec)
   passed  45/47  tramp-test44-delay-load (1.089584 sec)
   passed  46/47  tramp-test44-recursive-load (1.738185 sec)
   passed  47/47  tramp-test44-remote-load-path (1.063835 sec)

Ran 47 tests, 47 results as expected, 0 unexpected (2019-08-07 12:18:04-0700, 113.624368 sec)
1 expected failures

make[1]: Leaving directory '/home/eggert/src/gnu/emacs/static-checking/test'

bug#36940: tests slowness and failure after recent Tramp changes

[Michael Albinus]

Paul Eggert <eggert@cs.ucla.edu> writes:

Hi Paul,

> Thanks, it does fix the failure. However, the test is still quite a
> bit slower for me than you even when I invoke it the way you suggest,
> as it takes 108 seconds for me compared to 30 seconds for you. The
> four slowest tests are:
>
>    passed  37/47  tramp-test35-remote-path (25.712913 sec)
>    passed  42/47  tramp-test41-utf8 (14.036743 sec)
>    passed  17/47  tramp-test12-rename-file (8.772317 sec)
>    passed  16/47  tramp-test11-copy-file (7.754914 sec)

My machine is about 10 years old (Ubuntu 19.04, Intel Core2 Duo T95,
4GB). It runs today

   passed  37/47  tramp-test35-remote-path (4.826182 sec)
   passed  42/47  tramp-test41-utf8 (2.885723 sec)
   passed  17/47  tramp-test12-rename-file (1.725029 sec)
   passed  16/47  tramp-test11-copy-file (1.437843 sec)

But experience has shown, that it easily doubles or triples the time if
there are parallel tasks. It would need more debugging on your machine
in order to understand, where the time is spent.

Best regards, Michael.

bug#36940: tests slowness and failure after recent Tramp changes

[Glenn Morris]

I suspect it is now unstable. On RHEL 7.6 at d5622eb:

for ((n=1;n<=100;n++)); do
  make lisp/net/tramp-tests SELECTOR='tramp-test19-directory-files-and-attributes' 2>&1 | grep -q '[^0] unexpected' && let fail++
done

echo $fail

returned 7 failures for me.

bug#36940: tests slowness and failure after recent Tramp changes

[Michael Albinus]

Glenn Morris <rgm@gnu.org> writes:

Hi Glenn,

> I suspect it is now unstable. On RHEL 7.6 at d5622eb:
>
> for ((n=1;n<=100;n++)); do
>   make lisp/net/tramp-tests
> SELECTOR='tramp-test19-directory-files-and-attributes' 2>&1 | grep -q
> '[^0] unexpected' && let fail++
> done
>
> echo $fail
>
> returned 7 failures for me.

Thanks, this is a very useful test. I've committed another patch to
master. With that patch, your test passes.

(Damn time arithmetic!)

Best regards, Michael.

bug#36940: tests slowness and failure after recent Tramp changes

[Paul Eggert]

Michael Albinus wrote:
> With that patch, your test passes.
> 
> (Damn time arithmetic!)

No, time arithmetic is fun! :-)

Your patch has several instances of (floor (float-time X)) that would be 
slightly better if written as (time-convert X 'integer), as the former has 
(unlikely) rounding errors that the latter lacks.

I assume that the test now uses integer timestamps because file systems 
routinely drop low-order parts of timestamps. But won't the test continue to 
have problems with filesystems whose timestamp resolution is 2 seconds? I have 
heard of such things.

bug#36940: tests slowness and failure after recent Tramp changes

[Michael Albinus]

Paul Eggert <eggert@cs.ucla.edu> writes:

Hi Paul,

> Your patch has several instances of (floor (float-time X)) that would
> be slightly better if written as (time-convert X 'integer), as the
> former has (unlikely) rounding errors that the latter lacks.
>
> I assume that the test now uses integer timestamps because file
> systems routinely drop low-order parts of timestamps. But won't the
> test continue to have problems with filesystems whose timestamp
> resolution is 2 seconds? I have heard of such things.

Thanks for the explanation.

Honestly, we have also a further problem. The tests compare time values
taken on different machines. It cannot be assumed that they are always
synchronized. Until now it works, but who knows.

The tests in tramp--test-file-attributes-equal-p do not require exact
time stamps. They just want to ensure, that time values in file
attributes are newer than the time the ert test case has started. I've
changed the test such a way, that it is compared with the start time
minus 60 seconds. This solves the two problems you have mentioned, and
it also allows a time offset of up to 60 seconds for the two machines in
question. This shall suffice for most of the caes in practice.

A more precise test would be to retrieve the ert test start time, as taken
from the remote machine. But I don't know of a general function doing this.

Best regards, Michael.

bug#36940: tests slowness and failure after recent Tramp changes

[Paul Eggert]

Michael Albinus wrote:

> A more precise test would be to retrieve the ert test start time, as taken
> from the remote machine. But I don't know of a general function doing this.

Can we do the equivalent of 'touch nonce-file' on the remote machine, and then 
retrieve the nonce-file's timestamp? That should be a reasonably-reliable way of 
getting a remote timestamp at the start of the test.

bug#36940: tests slowness and failure after recent Tramp changes

[Michael Albinus]

Paul Eggert <eggert@cs.ucla.edu> writes:

Hi Paul,

> Can we do the equivalent of 'touch nonce-file' on the remote machine,
> and then retrieve the nonce-file's timestamp? That should be a
> reasonably-reliable way of getting a remote timestamp at the start of
> the test.

"touch ..." would work only for ssh-like Tramp methods, which is the
minority. I've applioed a similar approach, using the modification time
of the very first remote file created in the test, as start test time.

Best regards, Michael.

bug#36940: tests slowness and failure after recent Tramp changes

[Michael Albinus]

Michael Albinus <michael.albinus@gmx.de> writes:

Hi Paul,

>> Can we do the equivalent of 'touch nonce-file' on the remote machine,
>> and then retrieve the nonce-file's timestamp? That should be a
>> reasonably-reliable way of getting a remote timestamp at the start of
>> the test.
>
> "touch ..." would work only for ssh-like Tramp methods, which is the
> minority. I've applied a similar approach, using the modification time
> of the very first remote file created in the test, as start test time.

I guess there's nothing left to do with this bug. Is it OK to close?

Best regards, Michael.

bug#36940: tests slowness and failure after recent Tramp changes

[Paul Eggert]

Michael Albinus wrote:
> I guess there's nothing left to do with this bug. Is it OK to close?

Sure, closing it now.

bug#36940: tests slowness and failure after recent Tramp changes

[Stefan Kangas]

[-- Attachment #1: Type: text/plain, Size: 835 bytes --]

Michael Albinus <michael.albinus@gmx.de> writes:

> I guess there's nothing left to do with this bug. Is it OK to close?

Hi Michael,

I'm still seeing failures on my MacOS machine on current master.  I
have attached a log with two failing tests from when I run "make
check" in the top level emacs folder as the file tramp-tests.log.

Weirdly enough, when I say "cd test ; make tramp-tests", I get six
errors instead -- but no log file is saved.  Not sure if I'm doing
something wrong here, but I've included the console output from this
test as tramp-tests2.console.log.  I tried running the tests in both
ways a couple of times, and this odd result is reproducible every
time.

Please let me know if there's anything I can do to help you investigate.

(Not sure if you want to reopen the bug report for this.)

Thanks,
Stefan Kangas

[-- Attachment #2: tramp-tests.log --]
[-- Type: application/octet-stream, Size: 6537 bytes --]

[-- Attachment #3: tramp-tests2.console.log --]
[-- Type: application/octet-stream, Size: 20766 bytes --]

Stefans-MBP:emacs skangas$ cd test
Stefans-MBP:test skangas$ make tramp-tests
  GEN      lisp/net/tramp-tests.log
Running 67 tests (2019-08-24 03:31:27+0200, selector `(not (tag :unstable))')
Remote directory: `/mock::/var/folders/pj/rhx0gxy15tv3vx6l3mdy0qvm0000gn/T/'
   passed   1/67  tramp-test00-availability (0.205403 sec)
   passed   2/67  tramp-test01-file-name-syntax (0.000399 sec)
   passed   3/67  tramp-test01-file-name-syntax-separate (0.077190 sec)
   passed   4/67  tramp-test01-file-name-syntax-simplified (0.000419 sec)
   passed   5/67  tramp-test02-file-name-dissect (0.121083 sec)
   passed   6/67  tramp-test02-file-name-dissect-separate (0.151633 sec)
   passed   7/67  tramp-test02-file-name-dissect-simplified (0.106512 sec)
   passed   8/67  tramp-test03-file-name-defaults (0.052698 sec)
   passed   9/67  tramp-test03-file-name-host-rules (0.050232 sec)
   passed  10/67  tramp-test03-file-name-method-rules (0.000433 sec)
   passed  11/67  tramp-test04-substitute-in-file-name (0.035610 sec)
   passed  12/67  tramp-test05-expand-file-name (0.003169 sec)
   failed  13/67  tramp-test05-expand-file-name-relative (0.121827 sec)
   passed  14/67  tramp-test06-directory-file-name (0.009590 sec)
   passed  15/67  tramp-test07-file-exists-p (0.490691 sec)
   passed  16/67  tramp-test08-file-local-copy (0.823549 sec)
   passed  17/67  tramp-test09-insert-file-contents (1.026627 sec)
Wrote /mock:Stefans-MBP:/var/folders/pj/rhx0gxy15tv3vx6l3mdy0qvm0000gn/T/tramp-testDW8b6j
Wrote /mock:Stefans-MBP:/var/folders/pj/rhx0gxy15tv3vx6l3mdy0qvm0000gn/T/tramp-testDW8b6j
Wrote /mock:Stefans-MBP:/var/folders/pj/rhx0gxy15tv3vx6l3mdy0qvm0000gn/T/tramp-testDW8b6j
Wrote /mock:Stefans-MBP:/:/var/folders/pj/rhx0gxy15tv3vx6l3mdy0qvm0000gn/T/tramp-testWXacXz
Wrote /mock:Stefans-MBP:/:/var/folders/pj/rhx0gxy15tv3vx6l3mdy0qvm0000gn/T/tramp-testWXacXz
Wrote /mock:Stefans-MBP:/:/var/folders/pj/rhx0gxy15tv3vx6l3mdy0qvm0000gn/T/tramp-testWXacXz
   passed  18/67  tramp-test10-write-region (4.588637 sec)




   passed  19/67  tramp-test10-write-region-file-precious-flag (1.720242 sec)
   passed  20/67  tramp-test11-copy-file (7.327117 sec)
   passed  21/67  tramp-test12-rename-file (7.976660 sec)
   passed  22/67  tramp-test13-make-directory (0.384379 sec)
   passed  23/67  tramp-test14-delete-directory (0.692390 sec)
   passed  24/67  tramp-test15-copy-directory (3.250158 sec)
   passed  25/67  tramp-test16-directory-files (0.868014 sec)
   passed  26/67  tramp-test16-file-expand-wildcards (1.120907 sec)
   passed  27/67  tramp-test17-dired-with-wildcards (1.980941 sec)
   passed  28/67  tramp-test17-insert-directory (1.280409 sec)
   passed  29/67  tramp-test18-file-attributes (1.184561 sec)
(t 3 501 20 (0 0 0 1000) (0 0 0 1000) (0 0 0 1000) 0 "drwxr-xr-x" nil 41369843 (-1 . 18))
(t 5 501 20 (0 0 0 1000) (0 0 0 1000) (0 0 0 1000) 0 "drwxr-xr-x" nil (631 . 16627) (-1 . 18))
Test tramp-test19-directory-files-and-attributes backtrace:
  signal(ert-test-failed (((should (tramp--test-file-attributes-equal-
  ert-fail(((should (tramp--test-file-attributes-equal-p (file-attribu
  (if (unwind-protect (setq value-4208 (apply fn-4206 args-4207)) (set
  (let (form-description-4210) (if (unwind-protect (setq value-4208 (a
  (let ((value-4208 'ert-form-evaluation-aborted-4209)) (let (form-des
  (let* ((fn-4206 #'tramp--test-file-attributes-equal-p) (args-4207 (c
  (let ((elt (car --dolist-tail--))) (let* ((fn-4206 #'tramp--test-fil
  (while --dolist-tail-- (let ((elt (car --dolist-tail--))) (let* ((fn
  (let ((--dolist-tail-- attr)) (while --dolist-tail-- (let ((elt (car
  (progn (make-directory tmp-name1) (let* ((fn-4191 #'file-directory-p
  (unwind-protect (progn (make-directory tmp-name1) (let* ((fn-4191 #'
  (let* ((tmp-name1 (tramp--test-make-temp-name nil quoted)) (tmp-name
  (let ((quoted (car --dolist-tail--))) (let* ((tmp-name1 (tramp--test
  (while --dolist-tail-- (let ((quoted (car --dolist-tail--))) (let* (
  (let ((--dolist-tail-- (if (tramp--test-expensive-test) '(nil t) '(n
  (closure (t) nil (let* ((fn-4186 #'tramp--test-enabled) (args-4187 (
  ert--run-test-internal(#s(ert--test-execution-info :test #s(ert-test
  ert-run-test(#s(ert-test :name tramp-test19-directory-files-and-attr
  ert-run-or-rerun-test(#s(ert--stats :selector (not ...) :tests [...
  ert-run-tests((not (tag :unstable)) #f(compiled-function (event-type
  ert-run-tests-batch((not (tag :unstable)))
  ert-run-tests-batch-and-exit((not (tag :unstable)))
  eval((ert-run-tests-batch-and-exit '(not (tag :unstable))) t)
  command-line-1(("-L" ":." "-l" "ert" "-l" "lisp/net/tramp-tests.el"
  command-line()
  normal-top-level()
Test tramp-test19-directory-files-and-attributes condition:
    (ert-test-failed
     ((should
       (tramp--test-file-attributes-equal-p
	(file-attributes ...)
	(cdr elt)))
      :form
      (tramp--test-file-attributes-equal-p
       (t 3 501 20
	  (23904 37780)
	  (23904 37780)
	  (23904 37780)
	  102 "drwxr-xr-x" nil ...)
       (t 5 501 20
	  (23904 37780)
	  (23904 37780)
	  (23904 37780)
	  170 "drwxr-xr-x" nil ...))
      :value nil :explanation
      (list-elt 1
		(different-atoms
		 (3 "#x3" "?")
		 (5 "#x5" "?")))))
   FAILED  30/67  tramp-test19-directory-files-and-attributes (0.996916 sec)
   passed  31/67  tramp-test20-file-modes (0.797850 sec)
   passed  32/67  tramp-test21-file-links (3.940499 sec)
Test tramp-test22-file-times backtrace:
  signal(ert-test-failed (((should (equal (tramp-compat-file-attribute
  ert-fail(((should (equal (tramp-compat-file-attribute-modification-t
  (if (unwind-protect (setq value-4543 (apply fn-4541 args-4542)) (set
  (let (form-description-4545) (if (unwind-protect (setq value-4543 (a
  (let ((value-4543 'ert-form-evaluation-aborted-4544)) (let (form-des
  (let* ((fn-4541 #'equal) (args-4542 (condition-case err (let ((signa
  (if (tramp-compat-time-equal-p (tramp-compat-file-attribute-modifica
  (progn (write-region "foo" nil tmp-name1) (let* ((fn-4526 #'file-exi
  (unwind-protect (progn (write-region "foo" nil tmp-name1) (let* ((fn
  (let ((tmp-name1 (tramp--test-make-temp-name nil quoted)) (tmp-name2
  (let ((quoted (car --dolist-tail--))) (let ((tmp-name1 (tramp--test-
  (while --dolist-tail-- (let ((quoted (car --dolist-tail--))) (let ((
  (let ((--dolist-tail-- (if (tramp--test-expensive-test) '(nil t) '(n
  (closure (t) nil (let* ((fn-4519 #'tramp--test-enabled) (args-4520 (
  ert--run-test-internal(#s(ert--test-execution-info :test #s(ert-test
  ert-run-test(#s(ert-test :name tramp-test22-file-times :documentatio
  ert-run-or-rerun-test(#s(ert--stats :selector (not ...) :tests [...
  ert-run-tests((not (tag :unstable)) #f(compiled-function (event-type
  ert-run-tests-batch((not (tag :unstable)))
  ert-run-tests-batch-and-exit((not (tag :unstable)))
  eval((ert-run-tests-batch-and-exit '(not (tag :unstable))) t)
  command-line-1(("-L" ":." "-l" "ert" "-l" "lisp/net/tramp-tests.el"
  command-line()
  normal-top-level()
Test tramp-test22-file-times condition:
    (ert-test-failed
     ((should
       (equal
	(tramp-compat-file-attribute-modification-time ...)
	(seconds-to-time 1)))
      :form
      (equal
       (0 1)
       (0 1 0 0))
      :value nil :explanation
      (proper-lists-of-different-length 2 4
					(0 1)
					(0 1 0 0)
					first-mismatch-at 2)))
   FAILED  33/67  tramp-test22-file-times (0.567633 sec)
   passed  34/67  tramp-test23-visited-file-modtime (0.719559 sec)
  skipped  35/67  tramp-test24-file-acl (0.122390 sec)
  skipped  36/67  tramp-test25-file-selinux (0.116752 sec)
   passed  37/67  tramp-test26-file-name-completion (2.317330 sec)
   passed  38/67  tramp-test27-load (1.157013 sec)
   passed  39/67  tramp-test28-process-file (0.734949 sec)
   passed  40/67  tramp-test29-start-file-process (2.121339 sec)
Test tramp-test30-make-process backtrace:
  signal(ert-test-failed (((should (string-match "killed\n\\'" (buffer
  ert-fail(((should (string-match "killed\n\\'" (buffer-string))) :for
  (if (unwind-protect (setq value-5139 (apply fn-5137 args-5138)) (set
  (let (form-description-5141) (if (unwind-protect (setq value-5139 (a
  (let ((value-5139 'ert-form-evaluation-aborted-5140)) (let (form-des
  (let* ((fn-5137 #'string-match) (args-5138 (condition-case err (let
  (progn (setq proc (with-no-warnings (make-process :name "test4" :buf
  (unwind-protect (progn (setq proc (with-no-warnings (make-process :n
  (save-current-buffer (set-buffer temp-buffer) (unwind-protect (progn
  (let ((temp-buffer (generate-new-buffer " *temp*"))) (save-current-b
  (unwind-protect (let ((temp-buffer (generate-new-buffer " *temp*")))
  (let ((default-directory tramp-test-temporary-file-directory) (tmp-n
  (let ((quoted (car --dolist-tail--))) (let ((default-directory tramp
  (while --dolist-tail-- (let ((quoted (car --dolist-tail--))) (let ((
  (let ((--dolist-tail-- (if (tramp--test-expensive-test) '(nil t) '(n
  (closure (t) nil (let* ((fn-5065 #'tramp--test-enabled) (args-5066 (
  ert--run-test-internal(#s(ert--test-execution-info :test #s(ert-test
  ert-run-test(#s(ert-test :name tramp-test30-make-process :documentat
  ert-run-or-rerun-test(#s(ert--stats :selector (not ...) :tests [...
  ert-run-tests((not (tag :unstable)) #f(compiled-function (event-type
  ert-run-tests-batch((not (tag :unstable)))
  ert-run-tests-batch-and-exit((not (tag :unstable)))
  eval((ert-run-tests-batch-and-exit '(not (tag :unstable))) t)
  command-line-1(("-L" ":." "-l" "ert" "-l" "lisp/net/tramp-tests.el"
  command-line()
  normal-top-level()
Test tramp-test30-make-process condition:
    (ert-test-failed
     ((should
       (string-match "killed
\\'"
		     (buffer-string)))
      :form
      (string-match "killed
\\'" "killed: 9
")
      :value nil))
   FAILED  41/67  tramp-test30-make-process (1.024851 sec)
   passed  42/67  tramp-test31-interrupt-process (0.267331 sec)
   passed  43/67  tramp-test32-shell-command (1.676633 sec)
   passed  44/67  tramp-test33-environment-variables (1.243075 sec)
   passed  45/67  tramp-test33-environment-variables-and-port-numbers (0.223764 sec)








   passed  46/67  tramp-test34-connection-local-variables (3.145334 sec)
   passed  47/67  tramp-test34-explicit-shell-file-name (0.424375 sec)
   passed  48/67  tramp-test35-exec-path (0.845873 sec)
   passed  49/67  tramp-test35-remote-path (4.215125 sec)
(Git)
   passed  50/67  tramp-test36-vc-registered (1.476998 sec)
   passed  51/67  tramp-test37-make-auto-save-file-name (0.213657 sec)
   passed  52/67  tramp-test38-find-backup-file-name (0.431431 sec)
   passed  53/67  tramp-test39-make-nearby-temp-file (0.458903 sec)
   passed  54/67  tramp-test40-special-characters (26.997250 sec)
   passed  55/67  tramp-test40-special-characters-with-ls (22.910366 sec)
   passed  56/67  tramp-test40-special-characters-with-perl (28.272597 sec)
  skipped  57/67  tramp-test40-special-characters-with-stat (0.196459 sec)
Test tramp-test41-utf8 backtrace:
  re-search-forward("^VAR_971C287AFA5BBEDD54ACB58B1CE718B4=Γυρίστε το
  apply(re-search-forward "^VAR_971C287AFA5BBEDD54ACB58B1CE718B4=Γυρί
  (setq value-5762 (apply fn-5760 args-5761))
  (unwind-protect (setq value-5762 (apply fn-5760 args-5761)) (setq fo
  (if (unwind-protect (setq value-5762 (apply fn-5760 args-5761)) (set
  (let (form-description-5764) (if (unwind-protect (setq value-5762 (a
  (let ((value-5762 'ert-form-evaluation-aborted-5763)) (let (form-des
  (let* ((fn-5760 #'re-search-forward) (args-5761 (condition-case err
  (progn (let* ((fn-5755 #'=) (args-5756 (condition-case err (let ((si
  (unwind-protect (progn (let* ((fn-5755 #'=) (args-5756 (condition-ca
  (save-current-buffer (set-buffer temp-buffer) (unwind-protect (progn
  (let ((temp-buffer (generate-new-buffer " *temp*"))) (save-current-b
  (let ((envvar (concat "VAR_" (upcase (md5 elt)))) (elt (encode-codin
  (let ((elt (car --dolist-tail--))) (let ((envvar (concat "VAR_" (upc
  (while --dolist-tail-- (let ((elt (car --dolist-tail--))) (let ((env
  (let ((--dolist-tail-- files)) (while --dolist-tail-- (let ((elt (ca
  (progn (let ((--dolist-tail-- files)) (while --dolist-tail-- (let ((
  (if (and (tramp--test-expensive-test) (tramp--test-sh-p)) (progn (le
  (progn (make-directory tmp-name1) (make-directory tmp-name2) (let ((
  (unwind-protect (progn (make-directory tmp-name1) (make-directory tm
  (let* ((tramp-test-temporary-file-directory (file-truename tramp-tes
  (let ((quoted (car --dolist-tail--))) (let* ((tramp-test-temporary-f
  (while --dolist-tail-- (let ((quoted (car --dolist-tail--))) (let* (
  (let ((--dolist-tail-- (if (and (tramp--test-expensive-test) (tramp-
  tramp--test-check-files("Γυρίστε το Γαλαξία με Ώτο Στοπ" "أصبح بوسعك
  apply(tramp--test-check-files ("Γυρίστε το Γαλαξία με Ώτο Στοπ" "أصب
  (let* ((utf8 (if (and (eq system-type 'darwin) (memq 'utf-8-hfs (cod
  tramp--test-utf8()
  (closure (t) nil (let* ((fn-5855 #'tramp--test-enabled) (args-5856 (
  ert--run-test-internal(#s(ert--test-execution-info :test #s(ert-test
  ert-run-test(#s(ert-test :name tramp-test41-utf8 :documentation "Che
  ert-run-or-rerun-test(#s(ert--stats :selector (not ...) :tests [...
  ert-run-tests((not (tag :unstable)) #f(compiled-function (event-type
  ert-run-tests-batch((not (tag :unstable)))
  ert-run-tests-batch-and-exit((not (tag :unstable)))
  eval((ert-run-tests-batch-and-exit '(not (tag :unstable))) t)
  command-line-1(("-L" ":." "-l" "ert" "-l" "lisp/net/tramp-tests.el"
  command-line()
  normal-top-level()
Test tramp-test41-utf8 condition:
    (search-failed "^VAR_971C287AFA5BBEDD54ACB58B1CE718B4=Γυρίστε το Γαλαξία με Ώτο Στοπ$")
   FAILED  58/67  tramp-test41-utf8 (35.641851 sec)
Test tramp-test41-utf8-with-ls backtrace:
  re-search-forward("^VAR_971C287AFA5BBEDD54ACB58B1CE718B4=Γυρίστε το
  apply(re-search-forward "^VAR_971C287AFA5BBEDD54ACB58B1CE718B4=Γυρί
  (setq value-5762 (apply fn-5760 args-5761))
  (unwind-protect (setq value-5762 (apply fn-5760 args-5761)) (setq fo
  (if (unwind-protect (setq value-5762 (apply fn-5760 args-5761)) (set
  (let (form-description-5764) (if (unwind-protect (setq value-5762 (a
  (let ((value-5762 'ert-form-evaluation-aborted-5763)) (let (form-des
  (let* ((fn-5760 #'re-search-forward) (args-5761 (condition-case err
  (progn (let* ((fn-5755 #'=) (args-5756 (condition-case err (let ((si
  (unwind-protect (progn (let* ((fn-5755 #'=) (args-5756 (condition-ca
  (save-current-buffer (set-buffer temp-buffer) (unwind-protect (progn
  (let ((temp-buffer (generate-new-buffer " *temp*"))) (save-current-b
  (let ((envvar (concat "VAR_" (upcase (md5 elt)))) (elt (encode-codin
  (let ((elt (car --dolist-tail--))) (let ((envvar (concat "VAR_" (upc
  (while --dolist-tail-- (let ((elt (car --dolist-tail--))) (let ((env
  (let ((--dolist-tail-- files)) (while --dolist-tail-- (let ((elt (ca
  (progn (let ((--dolist-tail-- files)) (while --dolist-tail-- (let ((
  (if (and (tramp--test-expensive-test) (tramp--test-sh-p)) (progn (le
  (progn (make-directory tmp-name1) (make-directory tmp-name2) (let ((
  (unwind-protect (progn (make-directory tmp-name1) (make-directory tm
  (let* ((tramp-test-temporary-file-directory (file-truename tramp-tes
  (let ((quoted (car --dolist-tail--))) (let* ((tramp-test-temporary-f
  (while --dolist-tail-- (let ((quoted (car --dolist-tail--))) (let* (
  (let ((--dolist-tail-- (if (and (tramp--test-expensive-test) (tramp-
  tramp--test-check-files("Γυρίστε το Γαλαξία με Ώτο Στοπ" "أصبح بوسعك
  apply(tramp--test-check-files ("Γυρίστε το Γαλαξία με Ώτο Στοπ" "أصب
  (let* ((utf8 (if (and (eq system-type 'darwin) (memq 'utf-8-hfs (cod
  tramp--test-utf8()
  (let ((tramp-connection-properties (append (list (cons (regexp-quote
  (closure (t) nil (let* ((fn-5950 #'tramp--test-enabled) (args-5951 (
  ert--run-test-internal(#s(ert--test-execution-info :test #s(ert-test
  ert-run-test(#s(ert-test :name tramp-test41-utf8-with-ls :documentat
  ert-run-or-rerun-test(#s(ert--stats :selector (not ...) :tests [...
  ert-run-tests((not (tag :unstable)) #f(compiled-function (event-type
  ert-run-tests-batch((not (tag :unstable)))
  ert-run-tests-batch-and-exit((not (tag :unstable)))
  eval((ert-run-tests-batch-and-exit '(not (tag :unstable))) t)
  command-line-1(("-L" ":." "-l" "ert" "-l" "lisp/net/tramp-tests.el"
  command-line()
  normal-top-level()
Test tramp-test41-utf8-with-ls condition:
    (search-failed "^VAR_971C287AFA5BBEDD54ACB58B1CE718B4=Γυρίστε το Γαλαξία με Ώτο Στοπ$")
   FAILED  59/67  tramp-test41-utf8-with-ls (29.942527 sec)
Test tramp-test41-utf8-with-perl backtrace:
  re-search-forward("^VAR_971C287AFA5BBEDD54ACB58B1CE718B4=Γυρίστε το
  apply(re-search-forward "^VAR_971C287AFA5BBEDD54ACB58B1CE718B4=Γυρί
  (setq value-5762 (apply fn-5760 args-5761))
  (unwind-protect (setq value-5762 (apply fn-5760 args-5761)) (setq fo
  (if (unwind-protect (setq value-5762 (apply fn-5760 args-5761)) (set
  (let (form-description-5764) (if (unwind-protect (setq value-5762 (a
  (let ((value-5762 'ert-form-evaluation-aborted-5763)) (let (form-des
  (let* ((fn-5760 #'re-search-forward) (args-5761 (condition-case err
  (progn (let* ((fn-5755 #'=) (args-5756 (condition-case err (let ((si
  (unwind-protect (progn (let* ((fn-5755 #'=) (args-5756 (condition-ca
  (save-current-buffer (set-buffer temp-buffer) (unwind-protect (progn
  (let ((temp-buffer (generate-new-buffer " *temp*"))) (save-current-b
  (let ((envvar (concat "VAR_" (upcase (md5 elt)))) (elt (encode-codin
  (let ((elt (car --dolist-tail--))) (let ((envvar (concat "VAR_" (upc
  (while --dolist-tail-- (let ((elt (car --dolist-tail--))) (let ((env
  (let ((--dolist-tail-- files)) (while --dolist-tail-- (let ((elt (ca
  (progn (let ((--dolist-tail-- files)) (while --dolist-tail-- (let ((
  (if (and (tramp--test-expensive-test) (tramp--test-sh-p)) (progn (le
  (progn (make-directory tmp-name1) (make-directory tmp-name2) (let ((
  (unwind-protect (progn (make-directory tmp-name1) (make-directory tm
  (let* ((tramp-test-temporary-file-directory (file-truename tramp-tes
  (let ((quoted (car --dolist-tail--))) (let* ((tramp-test-temporary-f
  (while --dolist-tail-- (let ((quoted (car --dolist-tail--))) (let* (
  (let ((--dolist-tail-- (if (and (tramp--test-expensive-test) (tramp-
  tramp--test-check-files("Γυρίστε το Γαλαξία με Ώτο Στοπ" "أصبح بوسعك
  apply(tramp--test-check-files ("Γυρίστε το Γαλαξία με Ώτο Στοπ" "أصب
  (let* ((utf8 (if (and (eq system-type 'darwin) (memq 'utf-8-hfs (cod
  tramp--test-utf8()
  (let ((tramp-connection-properties (append (list (cons (regexp-quote
  (closure (t) nil (let* ((fn-5915 #'tramp--test-enabled) (args-5916 (
  ert--run-test-internal(#s(ert--test-execution-info :test #s(ert-test
  ert-run-test(#s(ert-test :name tramp-test41-utf8-with-perl :document
  ert-run-or-rerun-test(#s(ert--stats :selector (not ...) :tests [...
  ert-run-tests((not (tag :unstable)) #f(compiled-function (event-type
  ert-run-tests-batch((not (tag :unstable)))
  ert-run-tests-batch-and-exit((not (tag :unstable)))
  eval((ert-run-tests-batch-and-exit '(not (tag :unstable))) t)
  command-line-1(("-L" ":." "-l" "ert" "-l" "lisp/net/tramp-tests.el"
  command-line()
  normal-top-level()
Test tramp-test41-utf8-with-perl condition:
    (search-failed "^VAR_971C287AFA5BBEDD54ACB58B1CE718B4=Γυρίστε το Γαλαξία με Ώτο Στοπ$")
   FAILED  60/67  tramp-test41-utf8-with-perl (36.502001 sec)
  skipped  61/67  tramp-test41-utf8-with-stat (0.124898 sec)
   passed  62/67  tramp-test42-file-system-info (0.168878 sec)
   passed  63/67  tramp-test44-auto-load (0.306299 sec)
   passed  64/67  tramp-test44-delay-load (0.299836 sec)
   passed  65/67  tramp-test44-recursive-load (0.408862 sec)
   passed  66/67  tramp-test44-remote-load-path (0.255876 sec)
   passed  67/67  tramp-test45-unload (0.281970 sec)

Ran 67 tests, 57 results as expected, 6 unexpected, 4 skipped (2019-08-24 03:35:43+0200, 255.865907 sec)
1 expected failures

6 unexpected results:
   FAILED  tramp-test19-directory-files-and-attributes
   FAILED  tramp-test22-file-times
   FAILED  tramp-test30-make-process
   FAILED  tramp-test41-utf8
   FAILED  tramp-test41-utf8-with-ls
   FAILED  tramp-test41-utf8-with-perl

4 skipped results:
  SKIPPED  tramp-test24-file-acl
  SKIPPED  tramp-test25-file-selinux
  SKIPPED  tramp-test40-special-characters-with-stat
  SKIPPED  tramp-test41-utf8-with-stat

make[1]: *** [lisp/net/tramp-tests.log] Error 1
make: *** [lisp/net/tramp-tests] Error 2
Stefans-MBP:test skangas$

bug#36940: tests slowness and failure after recent Tramp changes

[Michael Albinus]

[-- Attachment #1: Type: text/plain, Size: 4129 bytes --]

Stefan Kangas <stefan@marxist.se> writes:

> Hi Michael,

Hi Stefan,

> I'm still seeing failures on my MacOS machine on current master.  I
> have attached a log with two failing tests from when I run "make
> check" in the top level emacs folder as the file tramp-tests.log.
>
> Weirdly enough, when I say "cd test ; make tramp-tests", I get six
> errors instead -- but no log file is saved.  Not sure if I'm doing
> something wrong here, but I've included the console output from this
> test as tramp-tests2.console.log.  I tried running the tests in both
> ways a couple of times, and this odd result is reproducible every
> time.

If you say "make check", the default ert selector is applied, which
excludes expensive tests. if you say "make FOO", all test from package
foo are applied, also the expensive tests. You see it by the different
numbers of tests, 47 vs 67 tests.

If you want to get a log file when running tests for package FOO, say
"make FOO.log". This seems to be broken now; will check.

All of this is described in test/README.

> (Not sure if you want to reopen the bug report for this.)

For the time being, I'll continue to reply here. If needed (more complex
failure, not reported initially here) we might need to create another
bug report.

> (t 3 501 20 (0 0 0 1000) (0 0 0 1000) (0 0 0 1000) 0 "drwxr-xr-x" nil 41369843 (-1 . 18))
> (t 5 501 20 (0 0 0 1000) (0 0 0 1000) (0 0 0 1000) 0 "drwxr-xr-x" nil (631 . 16627) (-1 . 18))
> Test tramp-test19-directory-files-and-attributes condition:
>     (ert-test-failed
>      ((should
>        (tramp--test-file-attributes-equal-p
> 	(file-attributes ...)
> 	(cdr elt)))
>       :form
>       (tramp--test-file-attributes-equal-p
>        (t 3 501 20
> 	  (23904 37780)
> 	  (23904 37780)
> 	  (23904 37780)
> 	  102 "drwxr-xr-x" nil ...)
>        (t 5 501 20
> 	  (23904 37780)
> 	  (23904 37780)
> 	  (23904 37780)
> 	  170 "drwxr-xr-x" nil ...))
>       :value nil :explanation
>       (list-elt 1
> 		(different-atoms
> 		 (3 "#x3" "?")
> 		 (5 "#x5" "?")))))
>    FAILED  30/67  tramp-test19-directory-files-and-attributes (0.996916 sec)

Well, this time it is because of a different inode number, 41369843 vs
(631 . 16627). Will check what's up.

> Test tramp-test22-file-times condition:
>     (ert-test-failed
>      ((should
>        (equal
> 	(tramp-compat-file-attribute-modification-time ...)
> 	(seconds-to-time 1)))
>       :form
>       (equal
>        (0 1)
>        (0 1 0 0))
>       :value nil :explanation
>       (proper-lists-of-different-length 2 4
> 					(0 1)
> 					(0 1 0 0)
> 					first-mismatch-at 2)))
>    FAILED  33/67  tramp-test22-file-times (0.567633 sec)

Grrr, the time stamps (0 1) and (0 1 0 0) are the same, but handled
differently internally. Fixed in master.

> Test tramp-test30-make-process condition:
>     (ert-test-failed
>      ((should
>        (string-match "killed
> \\'"
> 		     (buffer-string)))
>       :form
>       (string-match "killed
> \\'" "killed: 9
> ")
>       :value nil))
>    FAILED  41/67  tramp-test30-make-process (1.024851 sec)

Ahh, the message on macOS is slightly different. Fixed in master.

> Test tramp-test41-utf8 condition:
>     (search-failed "^VAR_971C287AFA5BBEDD54ACB58B1CE718B4=Γυρίστε το Γαλαξία με Ώτο Στοπ$")
>    FAILED  58/67  tramp-test41-utf8 (35.641851 sec)

> Test tramp-test41-utf8-with-ls condition:
>     (search-failed "^VAR_971C287AFA5BBEDD54ACB58B1CE718B4=Γυρίστε το Γαλαξία με Ώτο Στοπ$")
>    FAILED  59/67  tramp-test41-utf8-with-ls (29.942527 sec)

> Test tramp-test41-utf8-with-perl condition:
>     (search-failed "^VAR_971C287AFA5BBEDD54ACB58B1CE718B4=Γυρίστε το Γαλαξία με Ώτο Στοπ$")
>    FAILED  60/67  tramp-test41-utf8-with-perl (36.502001 sec)

These three errors are basically the same. Could you please apply the
following patch to tramp-tests.el, and show me the output? You might run

make -C test tramp-tests >tramp-tests.log 2>&1


[-- Warning: decoded text below may be mangled, UTF-8 assumed --]
[-- Attachment #2: Type: text/x-diff, Size: 546 bytes --]

diff --git a/test/lisp/net/tramp-tests.el b/test/lisp/net/tramp-tests.el
index 180f746c64..42d44f780b 100644
--- a/test/lisp/net/tramp-tests.el
+++ b/test/lisp/net/tramp-tests.el
@@ -5459,7 +5459,8 @@ tramp--test-utf8
   (skip-unless (not (tramp--test-windows-nt-and-batch)))
   (skip-unless (not (tramp--test-windows-nt-and-pscp-psftp-p)))

-  (tramp--test-utf8))
+  (tramp--test-instrument-test-case 10
+  (tramp--test-utf8)))

 (ert-deftest tramp-test41-utf8-with-stat ()
   "Check UTF8 encoding in file names and file contents.

[-- Attachment #3: Type: text/plain, Size: 51 bytes --]


> Thanks,
> Stefan Kangas

Best regards, Michael.

bug#36940: tests slowness and failure after recent Tramp changes

[Stefan Kangas]

Michael Albinus <michael.albinus@gmx.de> writes:

> Grrr, the time stamps (0 1) and (0 1 0 0) are the same, but handled
> differently internally. Fixed in master.

> Ahh, the message on macOS is slightly different. Fixed in master.

Thanks, down to 4 unexpected results now.

> These three errors are basically the same. Could you please apply the
> following patch to tramp-tests.el, and show me the output? You might run
>
> make -C test tramp-tests >tramp-tests.log 2>&1

I've done that, but I'll send you the file off list since it's
approximately 10 MB.

Best regards,
Stefan Kangas

bug#36940: tests slowness and failure after recent Tramp changes

[Michael Albinus]

Stefan Kangas <stefan@marxist.se> writes:

> Hi again,

Hi Stefan,

> Thanks a lot for working on this.  Please find attached the log file
> you requested, and do tell me if there is anything more I can do to
> help.

What I see is that the string to be searched for in the tests is
different from what the test should use. The test declares the string

"Γυρίστε το Γαλαξία με Ώτο Στοπ"

The fourth character is "ί", which is 

character: ί (displayed as ί) (codepoint 943, #o1657, #x3af)
name: GREEK SMALL LETTER IOTA WITH TONOS

In your search, the following string is used instead

"Γυρίστε το Γαλαξία με Ώτο Στοπ"

The fourth character is replaced by the two characters "ί", which are

character: ι (displayed as ι) (codepoint 953, #o1671, #x3b9)
name: GREEK SMALL LETTER IOTA

character: ́ (displayed as ́) (codepoint 769, #o1401, #x301)
name: COMBINING ACUTE ACCENT

I have no idea how and why the replacement happened. Could somebody with
UTF-8 background chime in, please? Or is it a font issue?

> Best regards,
> Stefan Kangas

Best regards, Michael.

bug#36940: tests slowness and failure after recent Tramp changes

[Eli Zaretskii]

> From: Michael Albinus <michael.albinus@gmx.de>
> Date: Sun, 25 Aug 2019 11:27:26 +0200
> Cc: Paul Eggert <eggert@cs.ucla.edu>, 36940@debbugs.gnu.org
> 
> What I see is that the string to be searched for in the tests is
> different from what the test should use. The test declares the string
> 
> "Γυρίστε το Γαλαξία με Ώτο Στοπ"
> 
> The fourth character is "ί", which is 
> 
> character: ί (displayed as ί) (codepoint 943, #o1657, #x3af)
> name: GREEK SMALL LETTER IOTA WITH TONOS
> 
> In your search, the following string is used instead
> 
> "Γυρίστε το Γαλαξία με Ώτο Στοπ"
> 
> The fourth character is replaced by the two characters "ί", which are
> 
> character: ι (displayed as ι) (codepoint 953, #o1671, #x3b9)
> name: GREEK SMALL LETTER IOTA
> 
> character: ́ (displayed as ́) (codepoint 769, #o1401, #x301)
> name: COMBINING ACUTE ACCENT
> 
> I have no idea how and why the replacement happened. Could somebody with
> UTF-8 background chime in, please? Or is it a font issue?

Darwin filesystem under utf-8-hfs uses decomposed strings for file
names.  What you see is the result of that decomposition: ί was
decomposed into ι followed by the acute accent, a combination that
displays the same as the original precomposed letter, but is different
when binary-compared.

I think you should run the strings through
ucs-normalize-HFS-NFD-string before comparing them, when the
en/decoding is done with utf-8-hfs.  Alternatively, use the facilities
in char-fold.el to generate a more lax regexp for your search in
tramp--test-check-files.

bug#36940: tests slowness and failure after recent Tramp changes

[Eli Zaretskii]

> Date: Sun, 25 Aug 2019 12:51:05 +0300
> From: Eli Zaretskii <eliz@gnu.org>
> Cc: eggert@cs.ucla.edu, stefan@marxist.se, 36940@debbugs.gnu.org
> 
> I think you should run the strings through
> ucs-normalize-HFS-NFD-string before comparing them, when the
> en/decoding is done with utf-8-hfs.  Alternatively, use the facilities
> in char-fold.el to generate a more lax regexp for your search in
> tramp--test-check-files.

As yet another possibility, avoid decomposable characters in the
strings you use altogether.  You can find out whether a given
character CH can be decomposed like this:

  (get-char-code-property CH 'decomposition)

For characters that have no decomposition, this should return a list
with a single element equal to CH.

bug#36940: tests slowness and failure after recent Tramp changes

[Michael Albinus]

Eli Zaretskii <eliz@gnu.org> writes:

Hi Eli,

>> I think you should run the strings through
>> ucs-normalize-HFS-NFD-string before comparing them, when the
>> en/decoding is done with utf-8-hfs.  Alternatively, use the facilities
>> in char-fold.el to generate a more lax regexp for your search in
>> tramp--test-check-files.
>
> As yet another possibility, avoid decomposable characters in the
> strings you use altogether.  You can find out whether a given
> character CH can be decomposed like this:
>
>   (get-char-code-property CH 'decomposition)
>
> For characters that have no decomposition, this should return a list
> with a single element equal to CH.

Well, tramp-test41-utf8 is intended to handle all whistles and bells
related to utf8 and Tramp. So this case shall be handled as well.

The interesting point is, that the test does *not* fail with such file
names. It is rather a regexp search in a shell output, which fails.

Best regards, Michael.

bug#36940: tests slowness and failure after recent Tramp changes

[Eli Zaretskii]

> From: Michael Albinus <michael.albinus@gmx.de>
> Cc: eggert@cs.ucla.edu,  stefan@marxist.se,  36940@debbugs.gnu.org
> Date: Sun, 25 Aug 2019 13:26:30 +0200
> 
> The interesting point is, that the test does *not* fail with such file
> names.

What does "not failing with such file names" entail?  Does the test
compare file names as strings, for example?

bug#36940: tests slowness and failure after recent Tramp changes

[Michael Albinus]

Eli Zaretskii <eliz@gnu.org> writes:

>> The interesting point is, that the test does *not* fail with such file
>> names.
>
> What does "not failing with such file names" entail?  Does the test
> compare file names as strings, for example?

Yes. But it compares file names as returned from the remote host, so
both strings are transformed the same way. I believe.

Best regards, Michael.

bug#36940: tests slowness and failure after recent Tramp changes

[Eli Zaretskii]

> From: Michael Albinus <michael.albinus@gmx.de>
> Cc: eggert@cs.ucla.edu,  stefan@marxist.se,  36940@debbugs.gnu.org
> Date: Sun, 25 Aug 2019 13:46:30 +0200
> 
> > What does "not failing with such file names" entail?  Does the test
> > compare file names as strings, for example?
> 
> Yes. But it compares file names as returned from the remote host, so
> both strings are transformed the same way. I believe.

Are the strings returned by the remote compared as unibyte strings?
If not, maybe there's a subtle bug in the comparison that does fail.
For example, could it be that you decode those strings as utf-8, not
as utf-8-hfs?  The latter should produce back the composed characters,
I think.

bug#36940: tests slowness and failure after recent Tramp changes

[Michael Albinus]

Eli Zaretskii <eliz@gnu.org> writes:

Hi Eli,

>> Yes. But it compares file names as returned from the remote host, so
>> both strings are transformed the same way. I believe.
>
> Are the strings returned by the remote compared as unibyte strings?
> If not, maybe there's a subtle bug in the comparison that does fail.
> For example, could it be that you decode those strings as utf-8, not
> as utf-8-hfs?  The latter should produce back the composed characters,
> I think.

The error happens while searching in a process buffer, which is set properly:

14:40:39.573073 tramp-open-connection-setup-interactive-shell (5) # Setting coding system to `utf-8-hfs' and `utf-8-hfs-mac'

But the search string needs to be normalized as proposed by you. Will do.

Best regards, Michael.

bug#36940: tests slowness and failure after recent Tramp changes

[Eli Zaretskii]

> From: Michael Albinus <michael.albinus@gmx.de>
> Cc: eggert@cs.ucla.edu,  stefan@marxist.se,  36940@debbugs.gnu.org
> Date: Mon, 26 Aug 2019 11:22:16 +0200
> 
> > Are the strings returned by the remote compared as unibyte strings?
> > If not, maybe there's a subtle bug in the comparison that does fail.
> > For example, could it be that you decode those strings as utf-8, not
> > as utf-8-hfs?  The latter should produce back the composed characters,
> > I think.
> 
> The error happens while searching in a process buffer, which is set properly:
> 
> 14:40:39.573073 tramp-open-connection-setup-interactive-shell (5) # Setting coding system to `utf-8-hfs' and `utf-8-hfs-mac'
> 
> But the search string needs to be normalized as proposed by you. Will do.

Sorry for bothering you, but now I am confused.  If the process
buffer's contents is decoded with utf-8-hfs, then decoding should have
composed the characters back, I believe.  So the text to be searched
in the buffer should use the precomposed character U+03AF GREEK SMALL
LETTER IOTA WITH TONOS.  Is that so?  And if so, is the problem with
the regexp you pass to re-search-forward?  Then where did that regexp
come from -- maybe the problem happens while you produce that regexp?

Feel free to ignore my questions if they are just a distraction, due
to my unfamiliarity with the text internals.

bug#36940: tests slowness and failure after recent Tramp changes

[Michael Albinus]

[-- Attachment #1: Type: text/plain, Size: 1709 bytes --]

Eli Zaretskii <eliz@gnu.org> writes:

Hi Eli,

>> The error happens while searching in a process buffer, which is set properly:
>>
>> 14:40:39.573073 tramp-open-connection-setup-interactive-shell (5) #
>> Setting coding system to `utf-8-hfs' and `utf-8-hfs-mac'
>>
>> But the search string needs to be normalized as proposed by you. Will do.
>
> Sorry for bothering you, but now I am confused.  If the process
> buffer's contents is decoded with utf-8-hfs, then decoding should have
> composed the characters back, I believe.  So the text to be searched
> in the buffer should use the precomposed character U+03AF GREEK SMALL
> LETTER IOTA WITH TONOS.  Is that so?  And if so, is the problem with
> the regexp you pass to re-search-forward?  Then where did that regexp
> come from -- maybe the problem happens while you produce that regexp?

Now I start to understand what happens. In tramp--test-check-files,
there is a loop over the test strings, which are used for different test
purposes. At the very end, an environment variable is set as

		  (setenv envvar elt)

When the failing regexp search is applied, the original string is not
taken, but the set environment variable

		    (should
		     (re-search-forward
		      (format
		       "^%s=%s$"
		       (regexp-quote envvar)
		       (regexp-quote (getenv envvar))))))))))

Likely, (getenv envvar) returns the encoded string, which fails. Using
the original string shall work.

> Feel free to ignore my questions if they are just a distraction, due
> to my unfamiliarity with the text internals.

No, you're very helpful as usual! Thanks!

Stefan, does the following patch solves the problem for you?


[-- Warning: decoded text below may be mangled, UTF-8 assumed --]
[-- Attachment #2: Type: text/x-patch, Size: 466 bytes --]

diff --git a/test/lisp/net/tramp-tests.el b/test/lisp/net/tramp-tests.el
index 557536a0eb..6ce1afa4a7 100644
--- a/test/lisp/net/tramp-tests.el
+++ b/test/lisp/net/tramp-tests.el
@@ -5288,7 +5288,7 @@ tramp--test-check-files
 		      (format
 		       "^%s=%s$"
 		       (regexp-quote envvar)
-		       (regexp-quote (getenv envvar))))))))))
+		       (regexp-quote elt)))))))))

 	;; Cleanup.
 	(ignore-errors (delete-directory tmp-name1 'recursive))

[-- Attachment #3: Type: text/plain, Size: 24 bytes --]


Best regards, Michael.

bug#36940: tests slowness and failure after recent Tramp changes

[Stefan Kangas]

[-- Attachment #1: Type: text/plain, Size: 688 bytes --]

Michael Albinus <michael.albinus@gmx.de> writes:

> Stefan, does the following patch solves the problem for you?

Current master gives the same results with or without that patch, unfortunately.

Without the patch:

4 unexpected results:
   FAILED  tramp-test19-directory-files-and-attributes
   FAILED  tramp-test41-utf8
   FAILED  tramp-test41-utf8-with-ls
   FAILED  tramp-test41-utf8-with-perl

With the patch:

4 unexpected results:
   FAILED  tramp-test19-directory-files-and-attributes
   FAILED  tramp-test41-utf8
   FAILED  tramp-test41-utf8-with-ls
   FAILED  tramp-test41-utf8-with-perl

Please find attached the console log of the test with that patch.

Thanks,
Stefan Kangas

[-- Attachment #2: tramp-tests3.console.log --]
[-- Type: application/octet-stream, Size: 17400 bytes --]

Stefans-MBP:emacs skangas$ patch -p1 </Users/skangas/Downloads/noname
(Stripping trailing CRs from patch.)
patching file test/lisp/net/tramp-tests.el
Stefans-MBP:emacs skangas$ make -C test tramp-tests
  ELC      lisp/net/tramp-tests.elc
  GEN      lisp/net/tramp-tests.log
Running 67 tests (2019-08-26 14:34:51+0200, selector `(not (tag :unstable))')
Remote directory: `/mock::/var/folders/pj/rhx0gxy15tv3vx6l3mdy0qvm0000gn/T/'
   passed   1/67  tramp-test00-availability (0.299451 sec)
   passed   2/67  tramp-test01-file-name-syntax (0.000437 sec)
   passed   3/67  tramp-test01-file-name-syntax-separate (0.076094 sec)
   passed   4/67  tramp-test01-file-name-syntax-simplified (0.000417 sec)
   passed   5/67  tramp-test02-file-name-dissect (0.109052 sec)
   passed   6/67  tramp-test02-file-name-dissect-separate (0.152015 sec)
   passed   7/67  tramp-test02-file-name-dissect-simplified (0.104941 sec)
   passed   8/67  tramp-test03-file-name-defaults (0.050757 sec)
   passed   9/67  tramp-test03-file-name-host-rules (0.044049 sec)
   passed  10/67  tramp-test03-file-name-method-rules (0.000441 sec)
   passed  11/67  tramp-test04-substitute-in-file-name (0.034500 sec)
   passed  12/67  tramp-test05-expand-file-name (0.001414 sec)
   failed  13/67  tramp-test05-expand-file-name-relative (0.117454 sec)
   passed  14/67  tramp-test06-directory-file-name (0.004428 sec)
   passed  15/67  tramp-test07-file-exists-p (0.502141 sec)
   passed  16/67  tramp-test08-file-local-copy (0.901133 sec)
   passed  17/67  tramp-test09-insert-file-contents (1.103025 sec)
Wrote /mock:Stefans-MBP:/var/folders/pj/rhx0gxy15tv3vx6l3mdy0qvm0000gn/T/tramp-tests3OdMn
Wrote /mock:Stefans-MBP:/var/folders/pj/rhx0gxy15tv3vx6l3mdy0qvm0000gn/T/tramp-tests3OdMn
Wrote /mock:Stefans-MBP:/var/folders/pj/rhx0gxy15tv3vx6l3mdy0qvm0000gn/T/tramp-tests3OdMn
Wrote /mock:Stefans-MBP:/:/var/folders/pj/rhx0gxy15tv3vx6l3mdy0qvm0000gn/T/tramp-testyOyDFq
Wrote /mock:Stefans-MBP:/:/var/folders/pj/rhx0gxy15tv3vx6l3mdy0qvm0000gn/T/tramp-testyOyDFq
Wrote /mock:Stefans-MBP:/:/var/folders/pj/rhx0gxy15tv3vx6l3mdy0qvm0000gn/T/tramp-testyOyDFq
   passed  18/67  tramp-test10-write-region (3.802068 sec)




   passed  19/67  tramp-test10-write-region-file-precious-flag (1.827084 sec)
   passed  20/67  tramp-test11-copy-file (9.652802 sec)
   passed  21/67  tramp-test12-rename-file (9.287349 sec)
   passed  22/67  tramp-test13-make-directory (0.519930 sec)
   passed  23/67  tramp-test14-delete-directory (0.787643 sec)
   passed  24/67  tramp-test15-copy-directory (4.828114 sec)
   passed  25/67  tramp-test16-directory-files (1.053164 sec)
   passed  26/67  tramp-test16-file-expand-wildcards (1.299853 sec)
   passed  27/67  tramp-test17-dired-with-wildcards (2.259441 sec)
   passed  28/67  tramp-test17-insert-directory (1.016985 sec)
   passed  29/67  tramp-test18-file-attributes (1.242548 sec)
(t 3 501 20 (0 0 0 1000) (0 0 0 1000) (0 0 0 1000) 0 "drwxr-xr-x" nil 41510723 (-1 . 18))
(t 5 501 20 (0 0 0 1000) (0 0 0 1000) (0 0 0 1000) 0 "drwxr-xr-x" nil 41510723 (-1 . 18))
Test tramp-test19-directory-files-and-attributes backtrace:
  signal(ert-test-failed (((should (tramp--test-file-attributes-equal-
  ert-fail(((should (tramp--test-file-attributes-equal-p (file-attribu
  (if (unwind-protect (setq value-4208 (apply fn-4206 args-4207)) (set
  (let (form-description-4210) (if (unwind-protect (setq value-4208 (a
  (let ((value-4208 'ert-form-evaluation-aborted-4209)) (let (form-des
  (let* ((fn-4206 #'tramp--test-file-attributes-equal-p) (args-4207 (c
  (let ((elt (car --dolist-tail--))) (let* ((fn-4206 #'tramp--test-fil
  (while --dolist-tail-- (let ((elt (car --dolist-tail--))) (let* ((fn
  (let ((--dolist-tail-- attr)) (while --dolist-tail-- (let ((elt (car
  (progn (make-directory tmp-name1) (let* ((fn-4191 #'file-directory-p
  (unwind-protect (progn (make-directory tmp-name1) (let* ((fn-4191 #'
  (let* ((tmp-name1 (tramp--test-make-temp-name nil quoted)) (tmp-name
  (let ((quoted (car --dolist-tail--))) (let* ((tmp-name1 (tramp--test
  (while --dolist-tail-- (let ((quoted (car --dolist-tail--))) (let* (
  (let ((--dolist-tail-- (if (tramp--test-expensive-test) '(nil t) '(n
  (closure (t) nil (let* ((fn-4186 #'tramp--test-enabled) (args-4187 (
  ert--run-test-internal(#s(ert--test-execution-info :test #s(ert-test
  ert-run-test(#s(ert-test :name tramp-test19-directory-files-and-attr
  ert-run-or-rerun-test(#s(ert--stats :selector (not ...) :tests [...
  ert-run-tests((not (tag :unstable)) #f(compiled-function (event-type
  ert-run-tests-batch((not (tag :unstable)))
  ert-run-tests-batch-and-exit((not (tag :unstable)))
  eval((ert-run-tests-batch-and-exit '(not (tag :unstable))) t)
  command-line-1(("-L" ":." "-l" "ert" "-l" "lisp/net/tramp-tests.el"
  command-line()
  normal-top-level()
Test tramp-test19-directory-files-and-attributes condition:
    (ert-test-failed
     ((should
       (tramp--test-file-attributes-equal-p
	(file-attributes ...)
	(cdr elt)))
      :form
      (tramp--test-file-attributes-equal-p
       (t 3 501 20
	  (23907 53781)
	  (23907 53781)
	  (23907 53781)
	  102 "drwxr-xr-x" nil ...)
       (t 5 501 20
	  (23907 53781)
	  (23907 53781)
	  (23907 53781)
	  170 "drwxr-xr-x" nil ...))
      :value nil :explanation
      (list-elt 1
		(different-atoms
		 (3 "#x3" "?")
		 (5 "#x5" "?")))))
   FAILED  30/67  tramp-test19-directory-files-and-attributes (0.664817 sec)
   passed  31/67  tramp-test20-file-modes (0.801483 sec)
   passed  32/67  tramp-test21-file-links (4.807237 sec)
   passed  33/67  tramp-test22-file-times (0.919323 sec)
   passed  34/67  tramp-test23-visited-file-modtime (0.819219 sec)
  skipped  35/67  tramp-test24-file-acl (0.145400 sec)
  skipped  36/67  tramp-test25-file-selinux (0.118059 sec)
   passed  37/67  tramp-test26-file-name-completion (2.320152 sec)
   passed  38/67  tramp-test27-load (1.086420 sec)
   passed  39/67  tramp-test28-process-file (0.604071 sec)
   passed  40/67  tramp-test29-start-file-process (1.063511 sec)
   passed  41/67  tramp-test30-make-process (1.650340 sec)
   passed  42/67  tramp-test31-interrupt-process (0.341796 sec)
   passed  43/67  tramp-test32-shell-command (1.780875 sec)
   passed  44/67  tramp-test33-environment-variables (1.239394 sec)
   passed  45/67  tramp-test33-environment-variables-and-port-numbers (0.230166 sec)








   passed  46/67  tramp-test34-connection-local-variables (3.351269 sec)
   passed  47/67  tramp-test34-explicit-shell-file-name (0.386735 sec)
   passed  48/67  tramp-test35-exec-path (0.867498 sec)
   passed  49/67  tramp-test35-remote-path (4.249264 sec)
(Git)
   passed  50/67  tramp-test36-vc-registered (1.457534 sec)
   passed  51/67  tramp-test37-make-auto-save-file-name (0.228322 sec)
   passed  52/67  tramp-test38-find-backup-file-name (0.429171 sec)
   passed  53/67  tramp-test39-make-nearby-temp-file (0.512099 sec)
   passed  54/67  tramp-test40-special-characters (25.844260 sec)
   passed  55/67  tramp-test40-special-characters-with-ls (20.562442 sec)
   passed  56/67  tramp-test40-special-characters-with-perl (25.768294 sec)
  skipped  57/67  tramp-test40-special-characters-with-stat (0.165451 sec)
Test tramp-test41-utf8 backtrace:
  re-search-forward("^VAR_971C287AFA5BBEDD54ACB58B1CE718B4=\316\223\31
  apply(re-search-forward "^VAR_971C287AFA5BBEDD54ACB58B1CE718B4=\316\
  (setq value-5762 (apply fn-5760 args-5761))
  (unwind-protect (setq value-5762 (apply fn-5760 args-5761)) (setq fo
  (if (unwind-protect (setq value-5762 (apply fn-5760 args-5761)) (set
  (let (form-description-5764) (if (unwind-protect (setq value-5762 (a
  (let ((value-5762 'ert-form-evaluation-aborted-5763)) (let (form-des
  (let* ((fn-5760 #'re-search-forward) (args-5761 (condition-case err
  (progn (let* ((fn-5755 #'=) (args-5756 (condition-case err (let ((si
  (unwind-protect (progn (let* ((fn-5755 #'=) (args-5756 (condition-ca
  (save-current-buffer (set-buffer temp-buffer) (unwind-protect (progn
  (let ((temp-buffer (generate-new-buffer " *temp*"))) (save-current-b
  (let ((envvar (concat "VAR_" (upcase (md5 elt)))) (elt (encode-codin
  (let ((elt (car --dolist-tail--))) (let ((envvar (concat "VAR_" (upc
  (while --dolist-tail-- (let ((elt (car --dolist-tail--))) (let ((env
  (let ((--dolist-tail-- files)) (while --dolist-tail-- (let ((elt (ca
  (progn (let ((--dolist-tail-- files)) (while --dolist-tail-- (let ((
  (if (and (tramp--test-expensive-test) (tramp--test-sh-p)) (progn (le
  (progn (make-directory tmp-name1) (make-directory tmp-name2) (let ((
  (unwind-protect (progn (make-directory tmp-name1) (make-directory tm
  (let* ((tramp-test-temporary-file-directory (file-truename tramp-tes
  (let ((quoted (car --dolist-tail--))) (let* ((tramp-test-temporary-f
  (while --dolist-tail-- (let ((quoted (car --dolist-tail--))) (let* (
  (let ((--dolist-tail-- (if (and (tramp--test-expensive-test) (tramp-
  tramp--test-check-files("Γυρίστε το Γαλαξία με Ώτο Στοπ" "أصبح بوسعك
  apply(tramp--test-check-files ("Γυρίστε το Γαλαξία με Ώτο Στοπ" "أصب
  (let* ((utf8 (if (and (eq system-type 'darwin) (memq 'utf-8-hfs (cod
  tramp--test-utf8()
  (closure (t) nil (let* ((fn-5855 #'tramp--test-enabled) (args-5856 (
  ert--run-test-internal(#s(ert--test-execution-info :test #s(ert-test
  ert-run-test(#s(ert-test :name tramp-test41-utf8 :documentation "Che
  ert-run-or-rerun-test(#s(ert--stats :selector (not ...) :tests [...
  ert-run-tests((not (tag :unstable)) #f(compiled-function (event-type
  ert-run-tests-batch((not (tag :unstable)))
  ert-run-tests-batch-and-exit((not (tag :unstable)))
  eval((ert-run-tests-batch-and-exit '(not (tag :unstable))) t)
  command-line-1(("-L" ":." "-l" "ert" "-l" "lisp/net/tramp-tests.el"
  command-line()
  normal-top-level()
Test tramp-test41-utf8 condition:
    (search-failed "^VAR_971C287AFA5BBEDD54ACB58B1CE718B4=\316\223\317\205\317\201\316\271\314\201\317\203\317\204\316\265 \317\204\316\277 \316\223\316\261\316\273\316\261\316\276\316\271\314\201\316\261 \316\274\316\265 \316\251\314\201\317\204\316\277 \316\243\317\204\316\277\317\200$")
   FAILED  58/67  tramp-test41-utf8 (33.218292 sec)
Test tramp-test41-utf8-with-ls backtrace:
  re-search-forward("^VAR_971C287AFA5BBEDD54ACB58B1CE718B4=\316\223\31
  apply(re-search-forward "^VAR_971C287AFA5BBEDD54ACB58B1CE718B4=\316\
  (setq value-5762 (apply fn-5760 args-5761))
  (unwind-protect (setq value-5762 (apply fn-5760 args-5761)) (setq fo
  (if (unwind-protect (setq value-5762 (apply fn-5760 args-5761)) (set
  (let (form-description-5764) (if (unwind-protect (setq value-5762 (a
  (let ((value-5762 'ert-form-evaluation-aborted-5763)) (let (form-des
  (let* ((fn-5760 #'re-search-forward) (args-5761 (condition-case err
  (progn (let* ((fn-5755 #'=) (args-5756 (condition-case err (let ((si
  (unwind-protect (progn (let* ((fn-5755 #'=) (args-5756 (condition-ca
  (save-current-buffer (set-buffer temp-buffer) (unwind-protect (progn
  (let ((temp-buffer (generate-new-buffer " *temp*"))) (save-current-b
  (let ((envvar (concat "VAR_" (upcase (md5 elt)))) (elt (encode-codin
  (let ((elt (car --dolist-tail--))) (let ((envvar (concat "VAR_" (upc
  (while --dolist-tail-- (let ((elt (car --dolist-tail--))) (let ((env
  (let ((--dolist-tail-- files)) (while --dolist-tail-- (let ((elt (ca
  (progn (let ((--dolist-tail-- files)) (while --dolist-tail-- (let ((
  (if (and (tramp--test-expensive-test) (tramp--test-sh-p)) (progn (le
  (progn (make-directory tmp-name1) (make-directory tmp-name2) (let ((
  (unwind-protect (progn (make-directory tmp-name1) (make-directory tm
  (let* ((tramp-test-temporary-file-directory (file-truename tramp-tes
  (let ((quoted (car --dolist-tail--))) (let* ((tramp-test-temporary-f
  (while --dolist-tail-- (let ((quoted (car --dolist-tail--))) (let* (
  (let ((--dolist-tail-- (if (and (tramp--test-expensive-test) (tramp-
  tramp--test-check-files("Γυρίστε το Γαλαξία με Ώτο Στοπ" "أصبح بوسعك
  apply(tramp--test-check-files ("Γυρίστε το Γαλαξία με Ώτο Στοπ" "أصب
  (let* ((utf8 (if (and (eq system-type 'darwin) (memq 'utf-8-hfs (cod
  tramp--test-utf8()
  (let ((tramp-connection-properties (append (list (cons (regexp-quote
  (closure (t) nil (let* ((fn-5950 #'tramp--test-enabled) (args-5951 (
  ert--run-test-internal(#s(ert--test-execution-info :test #s(ert-test
  ert-run-test(#s(ert-test :name tramp-test41-utf8-with-ls :documentat
  ert-run-or-rerun-test(#s(ert--stats :selector (not ...) :tests [...
  ert-run-tests((not (tag :unstable)) #f(compiled-function (event-type
  ert-run-tests-batch((not (tag :unstable)))
  ert-run-tests-batch-and-exit((not (tag :unstable)))
  eval((ert-run-tests-batch-and-exit '(not (tag :unstable))) t)
  command-line-1(("-L" ":." "-l" "ert" "-l" "lisp/net/tramp-tests.el"
  command-line()
  normal-top-level()
Test tramp-test41-utf8-with-ls condition:
    (search-failed "^VAR_971C287AFA5BBEDD54ACB58B1CE718B4=\316\223\317\205\317\201\316\271\314\201\317\203\317\204\316\265 \317\204\316\277 \316\223\316\261\316\273\316\261\316\276\316\271\314\201\316\261 \316\274\316\265 \316\251\314\201\317\204\316\277 \316\243\317\204\316\277\317\200$")
   FAILED  59/67  tramp-test41-utf8-with-ls (25.987484 sec)
Test tramp-test41-utf8-with-perl backtrace:
  re-search-forward("^VAR_971C287AFA5BBEDD54ACB58B1CE718B4=\316\223\31
  apply(re-search-forward "^VAR_971C287AFA5BBEDD54ACB58B1CE718B4=\316\
  (setq value-5762 (apply fn-5760 args-5761))
  (unwind-protect (setq value-5762 (apply fn-5760 args-5761)) (setq fo
  (if (unwind-protect (setq value-5762 (apply fn-5760 args-5761)) (set
  (let (form-description-5764) (if (unwind-protect (setq value-5762 (a
  (let ((value-5762 'ert-form-evaluation-aborted-5763)) (let (form-des
  (let* ((fn-5760 #'re-search-forward) (args-5761 (condition-case err
  (progn (let* ((fn-5755 #'=) (args-5756 (condition-case err (let ((si
  (unwind-protect (progn (let* ((fn-5755 #'=) (args-5756 (condition-ca
  (save-current-buffer (set-buffer temp-buffer) (unwind-protect (progn
  (let ((temp-buffer (generate-new-buffer " *temp*"))) (save-current-b
  (let ((envvar (concat "VAR_" (upcase (md5 elt)))) (elt (encode-codin
  (let ((elt (car --dolist-tail--))) (let ((envvar (concat "VAR_" (upc
  (while --dolist-tail-- (let ((elt (car --dolist-tail--))) (let ((env
  (let ((--dolist-tail-- files)) (while --dolist-tail-- (let ((elt (ca
  (progn (let ((--dolist-tail-- files)) (while --dolist-tail-- (let ((
  (if (and (tramp--test-expensive-test) (tramp--test-sh-p)) (progn (le
  (progn (make-directory tmp-name1) (make-directory tmp-name2) (let ((
  (unwind-protect (progn (make-directory tmp-name1) (make-directory tm
  (let* ((tramp-test-temporary-file-directory (file-truename tramp-tes
  (let ((quoted (car --dolist-tail--))) (let* ((tramp-test-temporary-f
  (while --dolist-tail-- (let ((quoted (car --dolist-tail--))) (let* (
  (let ((--dolist-tail-- (if (and (tramp--test-expensive-test) (tramp-
  tramp--test-check-files("Γυρίστε το Γαλαξία με Ώτο Στοπ" "أصبح بوسعك
  apply(tramp--test-check-files ("Γυρίστε το Γαλαξία με Ώτο Στοπ" "أصب
  (let* ((utf8 (if (and (eq system-type 'darwin) (memq 'utf-8-hfs (cod
  tramp--test-utf8()
  (let ((tramp-connection-properties (append (list (cons (regexp-quote
  (closure (t) nil (let* ((fn-5915 #'tramp--test-enabled) (args-5916 (
  ert--run-test-internal(#s(ert--test-execution-info :test #s(ert-test
  ert-run-test(#s(ert-test :name tramp-test41-utf8-with-perl :document
  ert-run-or-rerun-test(#s(ert--stats :selector (not ...) :tests [...
  ert-run-tests((not (tag :unstable)) #f(compiled-function (event-type
  ert-run-tests-batch((not (tag :unstable)))
  ert-run-tests-batch-and-exit((not (tag :unstable)))
  eval((ert-run-tests-batch-and-exit '(not (tag :unstable))) t)
  command-line-1(("-L" ":." "-l" "ert" "-l" "lisp/net/tramp-tests.el"
  command-line()
  normal-top-level()
Test tramp-test41-utf8-with-perl condition:
    (search-failed "^VAR_971C287AFA5BBEDD54ACB58B1CE718B4=\316\223\317\205\317\201\316\271\314\201\317\203\317\204\316\265 \317\204\316\277 \316\223\316\261\316\273\316\261\316\276\316\271\314\201\316\261 \316\274\316\265 \316\251\314\201\317\204\316\277 \316\243\317\204\316\277\317\200$")
   FAILED  60/67  tramp-test41-utf8-with-perl (32.801833 sec)
  skipped  61/67  tramp-test41-utf8-with-stat (0.103301 sec)
   passed  62/67  tramp-test42-file-system-info (0.138559 sec)
   passed  63/67  tramp-test44-auto-load (0.283807 sec)
   passed  64/67  tramp-test44-delay-load (0.278579 sec)
   passed  65/67  tramp-test44-recursive-load (0.391351 sec)
   passed  66/67  tramp-test44-remote-load-path (0.222249 sec)
   passed  67/67  tramp-test45-unload (0.235461 sec)

Ran 67 tests, 59 results as expected, 4 unexpected, 4 skipped (2019-08-26 14:38:55+0200, 243.084439 sec)
1 expected failures

4 unexpected results:
   FAILED  tramp-test19-directory-files-and-attributes
   FAILED  tramp-test41-utf8
   FAILED  tramp-test41-utf8-with-ls
   FAILED  tramp-test41-utf8-with-perl

4 skipped results:
  SKIPPED  tramp-test24-file-acl
  SKIPPED  tramp-test25-file-selinux
  SKIPPED  tramp-test40-special-characters-with-stat
  SKIPPED  tramp-test41-utf8-with-stat

make[1]: *** [lisp/net/tramp-tests.log] Error 1
make: *** [lisp/net/tramp-tests] Error 2

bug#36940: tests slowness and failure after recent Tramp changes

[Michael Albinus]

Stefan Kangas <stefan@marxist.se> writes:

Hi Stefan,

>> Stefan, does the following patch solves the problem for you?
>
> Current master gives the same results with or without that patch, unfortunately.

It's a pity I have no Mac for own testing ...

> Without the patch:
>
> 4 unexpected results:
>    FAILED  tramp-test19-directory-files-and-attributes

Well, there was also a difference in the link number. Fixed in master.

(I have no idea why it happens only for you.)

>    FAILED  tramp-test41-utf8
>    FAILED  tramp-test41-utf8-with-ls
>    FAILED  tramp-test41-utf8-with-perl

Hmm, under macOS the search string must be encoded as Eli has
suggested. I've pushed a respective patch to master.

Could you, please, check again?

> Thanks,
> Stefan Kangas

Thanks for your patience, and best regards, Michael.

bug#36940: tests slowness and failure after recent Tramp changes

[Stefan Kangas]

[-- Attachment #1: Type: text/plain, Size: 625 bytes --]

Michael Albinus <michael.albinus@gmx.de> writes:

> It's a pity I have no Mac for own testing ...

I can imagine it must be frustrating.  I'm trying to respond quickly
in order to minimize the turnaround time.  Thanks for your continued
efforts to fix this.

> Could you, please, check again?

Absolutely.  On current master (commit f87ace2aed), I'm now seeing:

3 unexpected results:
   FAILED  tramp-test41-utf8
   FAILED  tramp-test41-utf8-with-ls
   FAILED  tramp-test41-utf8-with-perl

Please find attached the console log for that run, using:
make -C test tramp-tests >tramp-tests.log 2>&1

Best regards,
Stefan Kangas

[-- Attachment #2: tramp-tests.log --]
[-- Type: application/octet-stream, Size: 14231 bytes --]

  ELC      lisp/net/tramp-tests.elc
  GEN      lisp/net/tramp-tests.log
Running 67 tests (2019-08-26 16:24:30+0200, selector `(not (tag :unstable))')
Remote directory: `/mock::/var/folders/pj/rhx0gxy15tv3vx6l3mdy0qvm0000gn/T/'
   passed   1/67  tramp-test00-availability (0.443867 sec)
   passed   2/67  tramp-test01-file-name-syntax (0.000522 sec)
   passed   3/67  tramp-test01-file-name-syntax-separate (0.107906 sec)
   passed   4/67  tramp-test01-file-name-syntax-simplified (0.000457 sec)
   passed   5/67  tramp-test02-file-name-dissect (0.311111 sec)
   passed   6/67  tramp-test02-file-name-dissect-separate (0.455001 sec)
   passed   7/67  tramp-test02-file-name-dissect-simplified (0.335975 sec)
   passed   8/67  tramp-test03-file-name-defaults (0.126350 sec)
   passed   9/67  tramp-test03-file-name-host-rules (0.088305 sec)
   passed  10/67  tramp-test03-file-name-method-rules (0.000637 sec)
   passed  11/67  tramp-test04-substitute-in-file-name (0.036021 sec)
   passed  12/67  tramp-test05-expand-file-name (0.004035 sec)
   failed  13/67  tramp-test05-expand-file-name-relative (0.250978 sec)
   passed  14/67  tramp-test06-directory-file-name (0.007372 sec)
   passed  15/67  tramp-test07-file-exists-p (1.353953 sec)
   passed  16/67  tramp-test08-file-local-copy (3.045665 sec)
   passed  17/67  tramp-test09-insert-file-contents (2.351553 sec)
Wrote /mock:Stefans-MBP:/var/folders/pj/rhx0gxy15tv3vx6l3mdy0qvm0000gn/T/tramp-test2IU45L
Wrote /mock:Stefans-MBP:/var/folders/pj/rhx0gxy15tv3vx6l3mdy0qvm0000gn/T/tramp-test2IU45L
Wrote /mock:Stefans-MBP:/var/folders/pj/rhx0gxy15tv3vx6l3mdy0qvm0000gn/T/tramp-test2IU45L
Wrote /mock:Stefans-MBP:/:/var/folders/pj/rhx0gxy15tv3vx6l3mdy0qvm0000gn/T/tramp-testdCbEc6
Wrote /mock:Stefans-MBP:/:/var/folders/pj/rhx0gxy15tv3vx6l3mdy0qvm0000gn/T/tramp-testdCbEc6
Wrote /mock:Stefans-MBP:/:/var/folders/pj/rhx0gxy15tv3vx6l3mdy0qvm0000gn/T/tramp-testdCbEc6
   passed  18/67  tramp-test10-write-region (8.563863 sec)




   passed  19/67  tramp-test10-write-region-file-precious-flag (4.307301 sec)
   passed  20/67  tramp-test11-copy-file (16.291176 sec)
   passed  21/67  tramp-test12-rename-file (18.235737 sec)
   passed  22/67  tramp-test13-make-directory (0.696270 sec)
   passed  23/67  tramp-test14-delete-directory (1.218106 sec)
   passed  24/67  tramp-test15-copy-directory (8.107725 sec)
   passed  25/67  tramp-test16-directory-files (1.629342 sec)
   passed  26/67  tramp-test16-file-expand-wildcards (2.595236 sec)
   passed  27/67  tramp-test17-dired-with-wildcards (3.572234 sec)
   passed  28/67  tramp-test17-insert-directory (1.984068 sec)
   passed  29/67  tramp-test18-file-attributes (2.030645 sec)
   passed  30/67  tramp-test19-directory-files-and-attributes (2.245941 sec)
   passed  31/67  tramp-test20-file-modes (2.446246 sec)
   passed  32/67  tramp-test21-file-links (8.120365 sec)
   passed  33/67  tramp-test22-file-times (1.522584 sec)
   passed  34/67  tramp-test23-visited-file-modtime (1.335509 sec)
  skipped  35/67  tramp-test24-file-acl (0.167290 sec)
  skipped  36/67  tramp-test25-file-selinux (0.178475 sec)
   passed  37/67  tramp-test26-file-name-completion (3.628330 sec)
   passed  38/67  tramp-test27-load (1.880983 sec)
   passed  39/67  tramp-test28-process-file (0.939504 sec)
   passed  40/67  tramp-test29-start-file-process (1.385620 sec)
   passed  41/67  tramp-test30-make-process (2.525758 sec)
   passed  42/67  tramp-test31-interrupt-process (0.400428 sec)
   passed  43/67  tramp-test32-shell-command (2.310231 sec)
   passed  44/67  tramp-test33-environment-variables (2.001958 sec)
   passed  45/67  tramp-test33-environment-variables-and-port-numbers (0.310196 sec)








   passed  46/67  tramp-test34-connection-local-variables (4.397120 sec)
   passed  47/67  tramp-test34-explicit-shell-file-name (0.546002 sec)
   passed  48/67  tramp-test35-exec-path (1.118682 sec)
   passed  49/67  tramp-test35-remote-path (5.578848 sec)
(Git)
   passed  50/67  tramp-test36-vc-registered (2.052423 sec)
   passed  51/67  tramp-test37-make-auto-save-file-name (0.322279 sec)
   passed  52/67  tramp-test38-find-backup-file-name (0.598714 sec)
   passed  53/67  tramp-test39-make-nearby-temp-file (0.660065 sec)
   passed  54/67  tramp-test40-special-characters (28.244084 sec)
   passed  55/67  tramp-test40-special-characters-with-ls (27.443249 sec)
   passed  56/67  tramp-test40-special-characters-with-perl (31.063808 sec)
  skipped  57/67  tramp-test40-special-characters-with-stat (0.197472 sec)
Test tramp-test41-utf8 backtrace:
  re-search-forward("^VAR_971C287AFA5BBEDD54ACB58B1CE718B4=Γυρίστε το
  apply(re-search-forward "^VAR_971C287AFA5BBEDD54ACB58B1CE718B4=Γυρί
  (setq value-5762 (apply fn-5760 args-5761))
  (unwind-protect (setq value-5762 (apply fn-5760 args-5761)) (setq fo
  (if (unwind-protect (setq value-5762 (apply fn-5760 args-5761)) (set
  (let (form-description-5764) (if (unwind-protect (setq value-5762 (a
  (let ((value-5762 'ert-form-evaluation-aborted-5763)) (let (form-des
  (let* ((fn-5760 #'re-search-forward) (args-5761 (condition-case err 
  (progn (let* ((fn-5755 #'=) (args-5756 (condition-case err (let ((si
  (unwind-protect (progn (let* ((fn-5755 #'=) (args-5756 (condition-ca
  (save-current-buffer (set-buffer temp-buffer) (unwind-protect (progn
  (let ((temp-buffer (generate-new-buffer " *temp*"))) (save-current-b
  (let ((envvar (concat "VAR_" (upcase (md5 elt)))) (elt (encode-codin
  (let ((elt (car --dolist-tail--))) (let ((envvar (concat "VAR_" (upc
  (while --dolist-tail-- (let ((elt (car --dolist-tail--))) (let ((env
  (let ((--dolist-tail-- files)) (while --dolist-tail-- (let ((elt (ca
  (progn (let ((--dolist-tail-- files)) (while --dolist-tail-- (let ((
  (if (and (tramp--test-expensive-test) (tramp--test-sh-p)) (progn (le
  (progn (make-directory tmp-name1) (make-directory tmp-name2) (let ((
  (unwind-protect (progn (make-directory tmp-name1) (make-directory tm
  (let* ((tramp-test-temporary-file-directory (file-truename tramp-tes
  (let ((quoted (car --dolist-tail--))) (let* ((tramp-test-temporary-f
  (while --dolist-tail-- (let ((quoted (car --dolist-tail--))) (let* (
  (let ((--dolist-tail-- (if (and (tramp--test-expensive-test) (tramp-
  tramp--test-check-files("Γυρίστε το Γαλαξία με Ώτο Στοπ" "أصبح بوسعك
  apply(tramp--test-check-files ("Γυρίστε το Γαλαξία με Ώτο Στοπ" "أصب
  (let* ((utf8 (if (and (eq system-type 'darwin) (memq 'utf-8-hfs (cod
  tramp--test-utf8()
  (closure (t) nil (let* ((fn-5855 #'tramp--test-enabled) (args-5856 (
  ert--run-test-internal(#s(ert--test-execution-info :test #s(ert-test
  ert-run-test(#s(ert-test :name tramp-test41-utf8 :documentation "Che
  ert-run-or-rerun-test(#s(ert--stats :selector (not ...) :tests [... 
  ert-run-tests((not (tag :unstable)) #f(compiled-function (event-type
  ert-run-tests-batch((not (tag :unstable)))
  ert-run-tests-batch-and-exit((not (tag :unstable)))
  eval((ert-run-tests-batch-and-exit '(not (tag :unstable))) t)
  command-line-1(("-L" ":." "-l" "ert" "-l" "lisp/net/tramp-tests.el" 
  command-line()
  normal-top-level()
Test tramp-test41-utf8 condition:
    (search-failed "^VAR_971C287AFA5BBEDD54ACB58B1CE718B4=Γυρίστε το Γαλαξία με Ώτο Στοπ$")
   FAILED  58/67  tramp-test41-utf8 (35.618526 sec)
Test tramp-test41-utf8-with-ls backtrace:
  re-search-forward("^VAR_971C287AFA5BBEDD54ACB58B1CE718B4=Γυρίστε το
  apply(re-search-forward "^VAR_971C287AFA5BBEDD54ACB58B1CE718B4=Γυρί
  (setq value-5762 (apply fn-5760 args-5761))
  (unwind-protect (setq value-5762 (apply fn-5760 args-5761)) (setq fo
  (if (unwind-protect (setq value-5762 (apply fn-5760 args-5761)) (set
  (let (form-description-5764) (if (unwind-protect (setq value-5762 (a
  (let ((value-5762 'ert-form-evaluation-aborted-5763)) (let (form-des
  (let* ((fn-5760 #'re-search-forward) (args-5761 (condition-case err 
  (progn (let* ((fn-5755 #'=) (args-5756 (condition-case err (let ((si
  (unwind-protect (progn (let* ((fn-5755 #'=) (args-5756 (condition-ca
  (save-current-buffer (set-buffer temp-buffer) (unwind-protect (progn
  (let ((temp-buffer (generate-new-buffer " *temp*"))) (save-current-b
  (let ((envvar (concat "VAR_" (upcase (md5 elt)))) (elt (encode-codin
  (let ((elt (car --dolist-tail--))) (let ((envvar (concat "VAR_" (upc
  (while --dolist-tail-- (let ((elt (car --dolist-tail--))) (let ((env
  (let ((--dolist-tail-- files)) (while --dolist-tail-- (let ((elt (ca
  (progn (let ((--dolist-tail-- files)) (while --dolist-tail-- (let ((
  (if (and (tramp--test-expensive-test) (tramp--test-sh-p)) (progn (le
  (progn (make-directory tmp-name1) (make-directory tmp-name2) (let ((
  (unwind-protect (progn (make-directory tmp-name1) (make-directory tm
  (let* ((tramp-test-temporary-file-directory (file-truename tramp-tes
  (let ((quoted (car --dolist-tail--))) (let* ((tramp-test-temporary-f
  (while --dolist-tail-- (let ((quoted (car --dolist-tail--))) (let* (
  (let ((--dolist-tail-- (if (and (tramp--test-expensive-test) (tramp-
  tramp--test-check-files("Γυρίστε το Γαλαξία με Ώτο Στοπ" "أصبح بوسعك
  apply(tramp--test-check-files ("Γυρίστε το Γαλαξία με Ώτο Στοπ" "أصب
  (let* ((utf8 (if (and (eq system-type 'darwin) (memq 'utf-8-hfs (cod
  tramp--test-utf8()
  (let ((tramp-connection-properties (append (list (cons (regexp-quote
  (closure (t) nil (let* ((fn-5950 #'tramp--test-enabled) (args-5951 (
  ert--run-test-internal(#s(ert--test-execution-info :test #s(ert-test
  ert-run-test(#s(ert-test :name tramp-test41-utf8-with-ls :documentat
  ert-run-or-rerun-test(#s(ert--stats :selector (not ...) :tests [... 
  ert-run-tests((not (tag :unstable)) #f(compiled-function (event-type
  ert-run-tests-batch((not (tag :unstable)))
  ert-run-tests-batch-and-exit((not (tag :unstable)))
  eval((ert-run-tests-batch-and-exit '(not (tag :unstable))) t)
  command-line-1(("-L" ":." "-l" "ert" "-l" "lisp/net/tramp-tests.el" 
  command-line()
  normal-top-level()
Test tramp-test41-utf8-with-ls condition:
    (search-failed "^VAR_971C287AFA5BBEDD54ACB58B1CE718B4=Γυρίστε το Γαλαξία με Ώτο Στοπ$")
   FAILED  59/67  tramp-test41-utf8-with-ls (28.100279 sec)
Test tramp-test41-utf8-with-perl backtrace:
  re-search-forward("^VAR_971C287AFA5BBEDD54ACB58B1CE718B4=Γυρίστε το
  apply(re-search-forward "^VAR_971C287AFA5BBEDD54ACB58B1CE718B4=Γυρί
  (setq value-5762 (apply fn-5760 args-5761))
  (unwind-protect (setq value-5762 (apply fn-5760 args-5761)) (setq fo
  (if (unwind-protect (setq value-5762 (apply fn-5760 args-5761)) (set
  (let (form-description-5764) (if (unwind-protect (setq value-5762 (a
  (let ((value-5762 'ert-form-evaluation-aborted-5763)) (let (form-des
  (let* ((fn-5760 #'re-search-forward) (args-5761 (condition-case err 
  (progn (let* ((fn-5755 #'=) (args-5756 (condition-case err (let ((si
  (unwind-protect (progn (let* ((fn-5755 #'=) (args-5756 (condition-ca
  (save-current-buffer (set-buffer temp-buffer) (unwind-protect (progn
  (let ((temp-buffer (generate-new-buffer " *temp*"))) (save-current-b
  (let ((envvar (concat "VAR_" (upcase (md5 elt)))) (elt (encode-codin
  (let ((elt (car --dolist-tail--))) (let ((envvar (concat "VAR_" (upc
  (while --dolist-tail-- (let ((elt (car --dolist-tail--))) (let ((env
  (let ((--dolist-tail-- files)) (while --dolist-tail-- (let ((elt (ca
  (progn (let ((--dolist-tail-- files)) (while --dolist-tail-- (let ((
  (if (and (tramp--test-expensive-test) (tramp--test-sh-p)) (progn (le
  (progn (make-directory tmp-name1) (make-directory tmp-name2) (let ((
  (unwind-protect (progn (make-directory tmp-name1) (make-directory tm
  (let* ((tramp-test-temporary-file-directory (file-truename tramp-tes
  (let ((quoted (car --dolist-tail--))) (let* ((tramp-test-temporary-f
  (while --dolist-tail-- (let ((quoted (car --dolist-tail--))) (let* (
  (let ((--dolist-tail-- (if (and (tramp--test-expensive-test) (tramp-
  tramp--test-check-files("Γυρίστε το Γαλαξία με Ώτο Στοπ" "أصبح بوسعك
  apply(tramp--test-check-files ("Γυρίστε το Γαλαξία με Ώτο Στοπ" "أصب
  (let* ((utf8 (if (and (eq system-type 'darwin) (memq 'utf-8-hfs (cod
  tramp--test-utf8()
  (let ((tramp-connection-properties (append (list (cons (regexp-quote
  (closure (t) nil (let* ((fn-5915 #'tramp--test-enabled) (args-5916 (
  ert--run-test-internal(#s(ert--test-execution-info :test #s(ert-test
  ert-run-test(#s(ert-test :name tramp-test41-utf8-with-perl :document
  ert-run-or-rerun-test(#s(ert--stats :selector (not ...) :tests [... 
  ert-run-tests((not (tag :unstable)) #f(compiled-function (event-type
  ert-run-tests-batch((not (tag :unstable)))
  ert-run-tests-batch-and-exit((not (tag :unstable)))
  eval((ert-run-tests-batch-and-exit '(not (tag :unstable))) t)
  command-line-1(("-L" ":." "-l" "ert" "-l" "lisp/net/tramp-tests.el" 
  command-line()
  normal-top-level()
Test tramp-test41-utf8-with-perl condition:
    (search-failed "^VAR_971C287AFA5BBEDD54ACB58B1CE718B4=Γυρίστε το Γαλαξία με Ώτο Στοπ$")
   FAILED  60/67  tramp-test41-utf8-with-perl (35.009720 sec)
  skipped  61/67  tramp-test41-utf8-with-stat (0.128297 sec)
   passed  62/67  tramp-test42-file-system-info (0.164035 sec)
   passed  63/67  tramp-test44-auto-load (0.300706 sec)
   passed  64/67  tramp-test44-delay-load (0.311023 sec)
   passed  65/67  tramp-test44-recursive-load (0.427972 sec)
   passed  66/67  tramp-test44-remote-load-path (0.260147 sec)
   passed  67/67  tramp-test45-unload (0.247259 sec)

Ran 67 tests, 60 results as expected, 3 unexpected, 4 skipped (2019-08-26 16:29:47+0200, 317.554747 sec)
1 expected failures

3 unexpected results:
   FAILED  tramp-test41-utf8
   FAILED  tramp-test41-utf8-with-ls
   FAILED  tramp-test41-utf8-with-perl

4 skipped results:
  SKIPPED  tramp-test24-file-acl
  SKIPPED  tramp-test25-file-selinux
  SKIPPED  tramp-test40-special-characters-with-stat
  SKIPPED  tramp-test41-utf8-with-stat

make[1]: *** [lisp/net/tramp-tests.log] Error 1
make: *** [lisp/net/tramp-tests] Error 2

bug#36940: tests slowness and failure after recent Tramp changes

[Michael Albinus]

[-- Attachment #1: Type: text/plain, Size: 809 bytes --]

Stefan Kangas <stefan@marxist.se> writes:

Hi Stefan,

> Absolutely.  On current master (commit f87ace2aed), I'm now seeing:
>
> 3 unexpected results:
>    FAILED  tramp-test41-utf8
>    FAILED  tramp-test41-utf8-with-ls
>    FAILED  tramp-test41-utf8-with-perl

Well, so we've fixed tramp-test19-directory-files-and-attributes at least.
Progress!

> Test tramp-test41-utf8 condition:
>     (search-failed "^VAR_971C287AFA5BBEDD54ACB58B1CE718B4=Γυρίστε το Γαλαξία με Ώτο Στοπ$")
>    FAILED  58/67  tramp-test41-utf8 (35.618526 sec)

Hmm, the string is still decomposed. Let's give it a last try, writing
some traces. Could you pls apply the patch, and send the result. You
could call

make -C test lisp/net/tramp-tests.log SELECTOR='tramp-test41-utf8'


[-- Warning: decoded text below may be mangled, UTF-8 assumed --]
[-- Attachment #2: Type: text/x-patch, Size: 921 bytes --]

diff --git a/test/lisp/net/tramp-tests.el b/test/lisp/net/tramp-tests.el
index 9930a2c9e1..69dadcd107 100644
--- a/test/lisp/net/tramp-tests.el
+++ b/test/lisp/net/tramp-tests.el
@@ -5288,6 +5288,14 @@ tramp--test-check-files
 		  (setenv "PS1")
 		  (with-temp-buffer
 		    (should (zerop (process-file "env" nil t nil)))
+                    (tramp--test-message
+                     "coding-sytem: `%s' `%s'"
+                     coding-system-for-read coding-system-for-write )
+                    (tramp--test-message "search: `%s'" (getenv envvar))
+                    (let ((coding-system-for-read 'no-conversion)
+                          (coding-system-for-write 'no-conversion))
+                      (tramp--test-message "search: `%s'" (getenv envvar))
+                      (tramp--test-message "buffer: `%s'" (buffer-string)))
 		    (goto-char (point-min))
 		    (should
 		     (re-search-forward

[-- Attachment #3: Type: text/plain, Size: 24 bytes --]


Best regards, Michael.

bug#36940: tests slowness and failure after recent Tramp changes

[Stefan Kangas]

[-- Attachment #1: Type: text/plain, Size: 486 bytes --]

Michael Albinus <michael.albinus@gmx.de> writes:

> Well, so we've fixed tramp-test19-directory-files-and-attributes at least.
> Progress!

Indeed, congratulations.

> Hmm, the string is still decomposed. Let's give it a last try, writing
> some traces. Could you pls apply the patch, and send the result. You
> could call
>
> make -C test lisp/net/tramp-tests.log SELECTOR='tramp-test41-utf8'

Please find attached the log of running that with your patch.

Best regards,
Stefan Kangas

[-- Attachment #2: tramp-tests.log --]
[-- Type: application/octet-stream, Size: 4714 bytes --]

  GEN      lisp/net/tramp-tests.log
Running 1 tests (2019-08-26 17:21:08+0200, selector `tramp-test41-utf8')
coding-sytem: `utf-8-hfs' `utf-8-hfs'
search: `Γυρίστε το Γαλαξία με Ώτο Στοπ'
search: `Γυρίστε το Γαλαξία με Ώτο Στοπ'
buffer: `TERM_PROGRAM=iTerm.app
TERM=dumb
SHELL=/usr/local/bin/bash
MAKEFLAGS=SELECTOR=tramp-test41-utf8
TMPDIR=/var/folders/pj/rhx0gxy15tv3vx6l3mdy0qvm0000gn/T/
Apple_PubSub_Socket_Render=/private/tmp/com.apple.launchd.DuDC5kOJA2/Render
TERM_PROGRAM_VERSION=3.3.0
TERM_SESSION_ID=w0t2p0:51E829DE-E74F-4C60-A261-BEC170355B39
LC_ALL=en_US.UTF-8
USER=skangas
MAKEOVERRIDES=${-*-command-variables-*-}
ENV=''
TEST_LOAD_EL=yes
SSH_AUTH_SOCK=/private/tmp/com.apple.launchd.TqwlYGTscH/Listeners
TMOUT=0
__CF_USER_TEXT_ENCODING=0x1F5:0x0:0x0
MAKELEVEL=1
PAGER=cat
MFLAGS=
PATH=/usr/bin:/bin:/usr/sbin:/sbin:/usr/local/bin:/usr/local/sbin
EMACS_TEST_DIRECTORY=/Users/skangas/wip/emacs/test
PWD=/private/var/folders/pj/rhx0gxy15tv3vx6l3mdy0qvm0000gn/T
LANG=en_SE@calendar=iso8601.UTF-8
ITERM_PROFILE=Default
XPC_FLAGS=0x0
PS3=
PS2=
XPC_SERVICE_NAME=0
EMACSLOADPATH=
HOME=/var/folders/pj/rhx0gxy15tv3vx6l3mdy0qvm0000gn/T/
COLORFGBG=7;0
SHLVL=3
LC_TERMINAL_VERSION=3.3.0
ITERM_SESSION_ID=w0t2p0:51E829DE-E74F-4C60-A261-BEC170355B39
LOGNAME=skangas
LC_CTYPE=''
SELECTOR=tramp-test41-utf8
PROMPT_COMMAND=
LC_TERMINAL=iTerm2
DISPLAY=/private/tmp/com.apple.launchd.sUzWGB3avt/org.macosforge.xquartz:0
INSIDE_EMACS=27.0.50,tramp:2.4.3-pre
HISTFILE=~/.tramp_history
COLORTERM=truecolor
_=/usr/bin/env
OLDPWD=/
VAR_971C287AFA5BBEDD54ACB58B1CE718B4=Γυρίστε το Γαλαξία με Ώτο Στοπ
'
Test tramp-test41-utf8 backtrace:
  re-search-forward("^VAR_971C287AFA5BBEDD54ACB58B1CE718B4=Γυρίστε το
  apply(re-search-forward "^VAR_971C287AFA5BBEDD54ACB58B1CE718B4=Γυρί
  (setq value-5762 (apply fn-5760 args-5761))
  (unwind-protect (setq value-5762 (apply fn-5760 args-5761)) (setq fo
  (if (unwind-protect (setq value-5762 (apply fn-5760 args-5761)) (set
  (let (form-description-5764) (if (unwind-protect (setq value-5762 (a
  (let ((value-5762 'ert-form-evaluation-aborted-5763)) (let (form-des
  (let* ((fn-5760 #'re-search-forward) (args-5761 (condition-case err 
  (progn (let* ((fn-5755 #'=) (args-5756 (condition-case err (let ((si
  (unwind-protect (progn (let* ((fn-5755 #'=) (args-5756 (condition-ca
  (save-current-buffer (set-buffer temp-buffer) (unwind-protect (progn
  (let ((temp-buffer (generate-new-buffer " *temp*"))) (save-current-b
  (let ((envvar (concat "VAR_" (upcase (md5 elt)))) (elt (encode-codin
  (let ((elt (car --dolist-tail--))) (let ((envvar (concat "VAR_" (upc
  (while --dolist-tail-- (let ((elt (car --dolist-tail--))) (let ((env
  (let ((--dolist-tail-- files)) (while --dolist-tail-- (let ((elt (ca
  (progn (let ((--dolist-tail-- files)) (while --dolist-tail-- (let ((
  (if (and (tramp--test-expensive-test) (tramp--test-sh-p)) (progn (le
  (progn (make-directory tmp-name1) (make-directory tmp-name2) (let ((
  (unwind-protect (progn (make-directory tmp-name1) (make-directory tm
  (let* ((tramp-test-temporary-file-directory (file-truename tramp-tes
  (let ((quoted (car --dolist-tail--))) (let* ((tramp-test-temporary-f
  (while --dolist-tail-- (let ((quoted (car --dolist-tail--))) (let* (
  (let ((--dolist-tail-- (if (and (tramp--test-expensive-test) (tramp-
  tramp--test-check-files("Γυρίστε το Γαλαξία με Ώτο Στοπ" "أصبح بوسعك
  apply(tramp--test-check-files ("Γυρίστε το Γαλαξία με Ώτο Στοπ" "أصب
  (let* ((utf8 (if (and (eq system-type 'darwin) (memq 'utf-8-hfs (cod
  tramp--test-utf8()
  (closure (t) nil (let* ((fn-5855 #'tramp--test-enabled) (args-5856 (
  ert--run-test-internal(#s(ert--test-execution-info :test #s(ert-test
  ert-run-test(#s(ert-test :name tramp-test41-utf8 :documentation "Che
  ert-run-or-rerun-test(#s(ert--stats :selector tramp-test41-utf8 :tes
  ert-run-tests(tramp-test41-utf8 #f(compiled-function (event-type &re
  ert-run-tests-batch(tramp-test41-utf8)
  ert-run-tests-batch-and-exit(tramp-test41-utf8)
  eval((ert-run-tests-batch-and-exit 'tramp-test41-utf8) t)
  command-line-1(("-L" ":." "-l" "ert" "-l" "lisp/net/tramp-tests.el" 
  command-line()
  normal-top-level()
Test tramp-test41-utf8 condition:
    (search-failed "^VAR_971C287AFA5BBEDD54ACB58B1CE718B4=Γυρίστε το Γαλαξία με Ώτο Στοπ$")
   FAILED  1/1  tramp-test41-utf8 (32.941148 sec)

Ran 1 tests, 0 results as expected, 1 unexpected (2019-08-26 17:21:42+0200, 33.874917 sec)

1 unexpected results:
   FAILED  tramp-test41-utf8

make: *** [lisp/net/tramp-tests.log] Error 1

bug#36940: tests slowness and failure after recent Tramp changes

[Michael Albinus]

[-- Attachment #1: Type: text/plain, Size: 155 bytes --]

Stefan Kangas <stefan@marxist.se> writes:

Hi Stefan,

> Please find attached the log of running that with your patch.

So let's try the following patch.


[-- Warning: decoded text below may be mangled, UTF-8 assumed --]
[-- Attachment #2: Type: text/x-patch, Size: 1982 bytes --]

diff --git a/test/lisp/net/tramp-tests.el b/test/lisp/net/tramp-tests.el
index 9930a2c9e1..8afd9f4ba4 100644
--- a/test/lisp/net/tramp-tests.el
+++ b/test/lisp/net/tramp-tests.el
@@ -5288,18 +5288,28 @@ tramp--test-check-files
 		  (setenv "PS1")
 		  (with-temp-buffer
 		    (should (zerop (process-file "env" nil t nil)))
-		    (goto-char (point-min))
-		    (should
-		     (re-search-forward
-                      ;; We must use proper encoding on macOS.  See
-                      ;; Bug#36940.
-                      (funcall
-	               (if (eq coding-system-for-read 'utf-8-hfs)
-                           'ucs-normalize-HFS-NFD-string 'identity)
-		       (format
-		        "^%s=%s$"
-		        (regexp-quote envvar)
-		        (regexp-quote (getenv envvar)))))))))))
+                    (tramp--test-message
+                     "coding-sytem: `%s' `%s'"
+                     coding-system-for-read coding-system-for-write )
+                    (tramp--test-message "search: `%s'" (getenv envvar))
+                    (let ((coding-system-for-read 'no-conversion)
+                          (coding-system-for-write 'no-conversion))
+                      (tramp--test-message
+                       "search: `%s'"
+                       (ucs-normalize-HFS-NFD-string (getenv envvar)))
+                      (tramp--test-message "buffer: `%s'" (buffer-string))
+		      (goto-char (point-min))
+		      (should
+		       (re-search-forward
+                        ;; We must use proper encoding on macOS.  See
+                        ;; Bug#36940.
+                        (funcall
+	                 (if (eq system-type 'darwin)
+                             'ucs-normalize-HFS-NFD-string 'identity)
+		         (format
+		          "^%s=%s$"
+		          (regexp-quote envvar)
+		          (regexp-quote (getenv envvar))))))))))))

 	;; Cleanup.
 	(ignore-errors (delete-directory tmp-name1 'recursive))

[-- Attachment #3: Type: text/plain, Size: 57 bytes --]


> Best regards,
> Stefan Kangas

Best regards, Michael.

bug#36940: tests slowness and failure after recent Tramp changes

[Stefan Kangas]

[-- Attachment #1: Type: text/plain, Size: 167 bytes --]

Michael Albinus <michael.albinus@gmx.de> writes:

> So let's try the following patch.

Sorry, it's still failing.  I've attached the log.

Best regards,
Stefan Kangas

[-- Attachment #2: tramp-tests.log --]
[-- Type: application/octet-stream, Size: 4821 bytes --]

  ELC      lisp/net/tramp-tests.elc
  GEN      lisp/net/tramp-tests.log
Running 1 tests (2019-08-26 19:44:36+0200, selector `tramp-test41-utf8')
coding-sytem: `utf-8-hfs' `utf-8-hfs'
search: `Γυρίστε το Γαλαξία με Ώτο Στοπ'
search: `Γυρίστε το Γαλαξία με Ώτο Στοπ'
buffer: `TERM_PROGRAM=iTerm.app
TERM=dumb
SHELL=/usr/local/bin/bash
MAKEFLAGS=SELECTOR=tramp-test41-utf8
TMPDIR=/var/folders/pj/rhx0gxy15tv3vx6l3mdy0qvm0000gn/T/
Apple_PubSub_Socket_Render=/private/tmp/com.apple.launchd.DuDC5kOJA2/Render
TERM_PROGRAM_VERSION=3.3.0
TERM_SESSION_ID=w0t2p0:51E829DE-E74F-4C60-A261-BEC170355B39
LC_ALL=en_US.UTF-8
USER=skangas
MAKEOVERRIDES=${-*-command-variables-*-}
ENV=''
TEST_LOAD_EL=yes
SSH_AUTH_SOCK=/private/tmp/com.apple.launchd.TqwlYGTscH/Listeners
TMOUT=0
__CF_USER_TEXT_ENCODING=0x1F5:0x0:0x0
MAKELEVEL=1
PAGER=cat
MFLAGS=
PATH=/usr/bin:/bin:/usr/sbin:/sbin:/usr/local/bin:/usr/local/sbin
EMACS_TEST_DIRECTORY=/Users/skangas/wip/emacs/test
PWD=/private/var/folders/pj/rhx0gxy15tv3vx6l3mdy0qvm0000gn/T
LANG=en_SE@calendar=iso8601.UTF-8
ITERM_PROFILE=Default
XPC_FLAGS=0x0
PS3=
PS2=
XPC_SERVICE_NAME=0
EMACSLOADPATH=
HOME=/var/folders/pj/rhx0gxy15tv3vx6l3mdy0qvm0000gn/T/
COLORFGBG=7;0
SHLVL=3
LC_TERMINAL_VERSION=3.3.0
ITERM_SESSION_ID=w0t2p0:51E829DE-E74F-4C60-A261-BEC170355B39
LOGNAME=skangas
LC_CTYPE=''
SELECTOR=tramp-test41-utf8
PROMPT_COMMAND=
LC_TERMINAL=iTerm2
DISPLAY=/private/tmp/com.apple.launchd.sUzWGB3avt/org.macosforge.xquartz:0
INSIDE_EMACS=27.0.50,tramp:2.4.3-pre
HISTFILE=~/.tramp_history
COLORTERM=truecolor
_=/usr/bin/env
OLDPWD=/
VAR_971C287AFA5BBEDD54ACB58B1CE718B4=Γυρίστε το Γαλαξία με Ώτο Στοπ
'
Test tramp-test41-utf8 backtrace:
  re-search-forward("^VAR_971C287AFA5BBEDD54ACB58B1CE718B4=Γυρίστε το
  apply(re-search-forward "^VAR_971C287AFA5BBEDD54ACB58B1CE718B4=Γυρί
  (setq value-5762 (apply fn-5760 args-5761))
  (unwind-protect (setq value-5762 (apply fn-5760 args-5761)) (setq fo
  (if (unwind-protect (setq value-5762 (apply fn-5760 args-5761)) (set
  (let (form-description-5764) (if (unwind-protect (setq value-5762 (a
  (let ((value-5762 'ert-form-evaluation-aborted-5763)) (let (form-des
  (let* ((fn-5760 #'re-search-forward) (args-5761 (condition-case err 
  (let ((coding-system-for-read 'no-conversion) (coding-system-for-wri
  (progn (let* ((fn-5755 #'=) (args-5756 (condition-case err (let ((si
  (unwind-protect (progn (let* ((fn-5755 #'=) (args-5756 (condition-ca
  (save-current-buffer (set-buffer temp-buffer) (unwind-protect (progn
  (let ((temp-buffer (generate-new-buffer " *temp*"))) (save-current-b
  (let ((envvar (concat "VAR_" (upcase (md5 elt)))) (elt (encode-codin
  (let ((elt (car --dolist-tail--))) (let ((envvar (concat "VAR_" (upc
  (while --dolist-tail-- (let ((elt (car --dolist-tail--))) (let ((env
  (let ((--dolist-tail-- files)) (while --dolist-tail-- (let ((elt (ca
  (progn (let ((--dolist-tail-- files)) (while --dolist-tail-- (let ((
  (if (and (tramp--test-expensive-test) (tramp--test-sh-p)) (progn (le
  (progn (make-directory tmp-name1) (make-directory tmp-name2) (let ((
  (unwind-protect (progn (make-directory tmp-name1) (make-directory tm
  (let* ((tramp-test-temporary-file-directory (file-truename tramp-tes
  (let ((quoted (car --dolist-tail--))) (let* ((tramp-test-temporary-f
  (while --dolist-tail-- (let ((quoted (car --dolist-tail--))) (let* (
  (let ((--dolist-tail-- (if (and (tramp--test-expensive-test) (tramp-
  tramp--test-check-files("Γυρίστε το Γαλαξία με Ώτο Στοπ" "أصبح بوسعك
  apply(tramp--test-check-files ("Γυρίστε το Γαλαξία με Ώτο Στοπ" "أصب
  (let* ((utf8 (if (and (eq system-type 'darwin) (memq 'utf-8-hfs (cod
  tramp--test-utf8()
  (closure (t) nil (let* ((fn-5855 #'tramp--test-enabled) (args-5856 (
  ert--run-test-internal(#s(ert--test-execution-info :test #s(ert-test
  ert-run-test(#s(ert-test :name tramp-test41-utf8 :documentation "Che
  ert-run-or-rerun-test(#s(ert--stats :selector tramp-test41-utf8 :tes
  ert-run-tests(tramp-test41-utf8 #f(compiled-function (event-type &re
  ert-run-tests-batch(tramp-test41-utf8)
  ert-run-tests-batch-and-exit(tramp-test41-utf8)
  eval((ert-run-tests-batch-and-exit 'tramp-test41-utf8) t)
  command-line-1(("-L" ":." "-l" "ert" "-l" "lisp/net/tramp-tests.el" 
  command-line()
  normal-top-level()
Test tramp-test41-utf8 condition:
    (search-failed "^VAR_971C287AFA5BBEDD54ACB58B1CE718B4=Γυρίστε το Γαλαξία με Ώτο Στοπ$")
   FAILED  1/1  tramp-test41-utf8 (39.336970 sec)

Ran 1 tests, 0 results as expected, 1 unexpected (2019-08-26 19:45:16+0200, 40.391884 sec)

1 unexpected results:
   FAILED  tramp-test41-utf8

make: *** [lisp/net/tramp-tests.log] Error 1

bug#36940: tests slowness and failure after recent Tramp changes

[Michael Albinus]

[-- Attachment #1: Type: text/plain, Size: 242 bytes --]

Stefan Kangas <stefan@marxist.se> writes:

> Sorry, it's still failing.  I've attached the log.

Let's try this one. If it also fails, I will disable this part of the
test for macOS. Tramp works correctly, and the check is a minor one only.


[-- Warning: decoded text below may be mangled, UTF-8 assumed --]
[-- Attachment #2: Type: text/x-patch, Size: 1866 bytes --]

diff --git a/test/lisp/net/tramp-tests.el b/test/lisp/net/tramp-tests.el
index 9930a2c9e1..3d5949b033 100644
--- a/test/lisp/net/tramp-tests.el
+++ b/test/lisp/net/tramp-tests.el
@@ -5288,18 +5288,26 @@ tramp--test-check-files
 		  (setenv "PS1")
 		  (with-temp-buffer
 		    (should (zerop (process-file "env" nil t nil)))
-		    (goto-char (point-min))
-		    (should
-		     (re-search-forward
-                      ;; We must use proper encoding on macOS.  See
-                      ;; Bug#36940.
-                      (funcall
-	               (if (eq coding-system-for-read 'utf-8-hfs)
-                           'ucs-normalize-HFS-NFD-string 'identity)
-		       (format
-		        "^%s=%s$"
-		        (regexp-quote envvar)
-		        (regexp-quote (getenv envvar)))))))))))
+                    (tramp--test-message
+                     "coding-sytem: `%s' `%s'"
+                     coding-system-for-read coding-system-for-write )
+                    (tramp--test-message "search: `%s'" (getenv envvar))
+                    ;; We must use proper encoding on macOS.  See
+                    ;; Bug#36940.
+                    (let ((system-type 'gnu/linux)
+                          (coding-system-for-read 'no-conversion)
+                          (coding-system-for-write 'no-conversion))
+                      (tramp--test-message
+                       "search: `%s'"
+                       (ucs-normalize-HFS-NFD-string (getenv envvar)))
+                      (tramp--test-message "buffer: `%s'" (buffer-string))
+		      (goto-char (point-min))
+		      (should
+		       (re-search-forward
+		        (format
+		         "^%s=%s$"
+		         (regexp-quote envvar)
+		         (regexp-quote (getenv envvar)))))))))))

 	;; Cleanup.
 	(ignore-errors (delete-directory tmp-name1 'recursive))

[-- Attachment #3: Type: text/plain, Size: 57 bytes --]


> Best regards,
> Stefan Kangas

Best regards, Michael.

bug#36940: tests slowness and failure after recent Tramp changes

[Stefan Kangas]

[-- Attachment #1: Type: text/plain, Size: 360 bytes --]

Michael Albinus <michael.albinus@gmx.de> writes:

> Let's try this one. If it also fails, I will disable this part of the
> test for macOS. Tramp works correctly, and the check is a minor one only.

Sorry for the delay.  I had a chance to run this on my macOS machine
again, and unfortunately it fails too.  I've attached the log.

Best regards,
Stefan Kangas

[-- Attachment #2: tramp-tests.log --]
[-- Type: application/octet-stream, Size: 3413 bytes --]

  GEN      lisp/net/tramp-tests.log
Running 1 tests (2019-08-27 18:31:39+0200, selector `tramp-test41-utf8')
Test tramp-test41-utf8 backtrace:
  signal(ert-test-failed (((should (equal (directory-files tmp-name1 n
  ert-fail(((should (equal (directory-files tmp-name1 nil directory-fi
  (if (unwind-protect (setq value-5682 (apply fn-5680 args-5681)) (set
  (let (form-description-5684) (if (unwind-protect (setq value-5682 (a
  (let ((value-5682 'ert-form-evaluation-aborted-5683)) (let (form-des
  (let* ((fn-5680 #'equal) (args-5681 (condition-case err (let ((signa
  (progn (make-directory tmp-name1) (make-directory tmp-name2) (let ((
  (unwind-protect (progn (make-directory tmp-name1) (make-directory tm
  (let* ((tramp-test-temporary-file-directory (file-truename tramp-tes
  (let ((quoted (car --dolist-tail--))) (let* ((tramp-test-temporary-f
  (while --dolist-tail-- (let ((quoted (car --dolist-tail--))) (let* (
  (let ((--dolist-tail-- (if (and (tramp--test-expensive-test) (tramp-
  tramp--test-check-files("Γυρίστε το Γαλαξία με Ώτο Στοπ" "أصبح بوسعك
  apply(tramp--test-check-files ("Γυρίστε το Γαλαξία με Ώτο Στοπ" "أصب
  (let* ((utf8 (if (and (eq system-type 'darwin) (memq 'utf-8-hfs (cod
  tramp--test-utf8()
  (closure (t) nil (let* ((fn-5855 #'tramp--test-enabled) (args-5856 (
  ert--run-test-internal(#s(ert--test-execution-info :test #s(ert-test
  ert-run-test(#s(ert-test :name tramp-test41-utf8 :documentation "Che
  ert-run-or-rerun-test(#s(ert--stats :selector tramp-test41-utf8 :tes
  ert-run-tests(tramp-test41-utf8 #f(compiled-function (event-type &re
  ert-run-tests-batch(tramp-test41-utf8)
  ert-run-tests-batch-and-exit(tramp-test41-utf8)
  eval((ert-run-tests-batch-and-exit 'tramp-test41-utf8) t)
  command-line-1(("-L" ":." "-l" "ert" "-l" "lisp/net/tramp-tests.el" 
  command-line()
  normal-top-level()
Test tramp-test41-utf8 condition:
    (ert-test-failed
     ((should
       (equal
	(directory-files tmp-name1 nil directory-files-no-dot-files-regexp)
	(sort ... ...)))
      :form
      (equal
       ("AVE ŠšŽžŒœŸ €" "Arabicالسّلام عليكم" "Bună ziua, bine aţi venit!" "Burmese (မ္ရန္‌မာ)မင္‍ဂလာပာ" "Cantonese (粵語,廣東話)早晨, 你好" "Catalan (Català)  Avui demà i ahir s'esfullarà una rosa" "Chinese (中文,普通话,汉语) 你好" "Chinese (中文,普通话,汉语) 妳好" "Chinese (中文,普通话,汉语)你好" "Er is een aantal manieren waarop je dit kan doen" ...)
       ("AVE ŠšŽžŒœŸ €" "Arabicالسّلام عليكم" "Bună ziua, bine aţi venit!" "Burmese (မ္ရန္‌မာ)မင္‍ဂလာပာ" "Cantonese (粵語,廣東話)早晨, 你好" "Catalan (Català)  Avui demà i ahir s'esfullarà una rosa" "Chinese (中文,普通话,汉语) 你好" "Chinese (中文,普通话,汉语) 妳好" "Chinese (中文,普通话,汉语)你好" "Er is een aantal manieren waarop je dit kan doen" ...))
      :value nil :explanation
      (list-elt 24
		(arrays-of-different-length 23 22 "Přejeme vám hezký den!" "Přejeme vám hezký den!" first-mismatch-at 16))))
   FAILED  1/1  tramp-test41-utf8 (17.897238 sec)

Ran 1 tests, 0 results as expected, 1 unexpected (2019-08-27 18:31:58+0200, 18.595599 sec)

1 unexpected results:
   FAILED  tramp-test41-utf8

make: *** [lisp/net/tramp-tests.log] Error 1

bug#36940: tests slowness and failure after recent Tramp changes

[Michael Albinus]

Stefan Kangas <stefan@marxist.se> writes:

>> Let's try this one. If it also fails, I will disable this part of the
>> test for macOS. Tramp works correctly, and the check is a minor one only.
>
> Sorry for the delay.  I had a chance to run this on my macOS machine
> again, and unfortunately it fails too.  I've attached the log.

So I have deactivated this part of the test for macOS. Tramp tests shall
pass now for you.

> Best regards,
> Stefan Kangas

Thanks for your continuous patience, and best regards, Michael.

bug#36940: tests slowness and failure after recent Tramp changes

[Stefan Kangas]

Michael Albinus <michael.albinus@gmx.de> writes:

> > Sorry for the delay.  I had a chance to run this on my macOS machine
> > again, and unfortunately it fails too.  I've attached the log.
>
> So I have deactivated this part of the test for macOS. Tramp tests shall
> pass now for you.

Sounds good.  And indeed, the tests are now passing.

> Thanks for your continuous patience, and best regards, Michael.

Thank you again for looking into this.

Best regards,
Stefan Kangas

bug#36940: tests slowness and failure after recent Tramp changes

[Michael Albinus]

Eli Zaretskii <eliz@gnu.org> writes:

Hi Eli,

> Darwin filesystem under utf-8-hfs uses decomposed strings for file
> names.  What you see is the result of that decomposition: ί was
> decomposed into ι followed by the acute accent, a combination that
> displays the same as the original precomposed letter, but is different
> when binary-compared.
>
> I think you should run the strings through
> ucs-normalize-HFS-NFD-string before comparing them, when the
> en/decoding is done with utf-8-hfs.  Alternatively, use the facilities
> in char-fold.el to generate a more lax regexp for your search in
> tramp--test-check-files.

Thanks, I will try to adapt the test accordingly. In core Tramp, nothing
needs to be changed I believe.

Best regards, Michael.

bug#36940: tests slowness and failure after recent Tramp changes

[Michael Albinus]

Michael Albinus <michael.albinus@gmx.de> writes:

Hi Stefan,

>>    FAILED  30/67  tramp-test19-directory-files-and-attributes (0.996916 sec)
>
> Well, this time it is because of a different inode number, 41369843 vs
> (631 . 16627). Will check what's up.

Fixed in master.

Best regards, Michael.

bug#36940: tests slowness and failure after recent Tramp changes

[Paul Eggert]

Michael Albinus wrote:
> Fixed in master.

Surely the fix won't work for most inode numbers greater than 2**53, because 
converting them to double and back will lose information due to rounding. Such 
inode numbers do exist in the wild, with FUSE and the like; see, e.g.:

https://forum.rclone.org/t/fuse-inode-number-aufs/215

bug#36940: tests slowness and failure after recent Tramp changes

[Michael Albinus]

Paul Eggert <eggert@cs.ucla.edu> writes:

Hi Paul,

> Surely the fix won't work for most inode numbers greater than 2**53,
> because converting them to double and back will lose information due
> to rounding.

Tramp uses this approach already at other places, I have just unified
the way inode numbers are retrieved. No problem reported over the years.

At which places in the code do you believe such errors will happen? The
floating number will be converted in tramp-convert-file-attributes, I
cannot see how a rounding error could happen there.

Practically, the inode slot of file-attributes doesn't seem to be
relevant. I haven't seen any code in Emacs which needs this
slot. Likely, Tramp spends too much effort computing it, I believe.

Best regards, Michael.

bug#36940: tests slowness and failure after recent Tramp changes

[Paul Eggert]

[-- Attachment #1: Type: text/plain, Size: 2437 bytes --]

Michael Albinus wrote:

> At which places in the code do you believe such errors will happen? The
> floating number will be converted in tramp-convert-file-attributes, I
> cannot see how a rounding error could happen there.

I think the rounding error doesn't happen there, as that code accurately 
converts the Lisp float to an integer or to a cons of integers. The rounding 
error happens in functions like tramp-send-command-and-read when the Emacs Lisp 
reader scans the string generated by the Perl code, and converts the string to a 
Lisp float.

For example, suppose the inode number is 2**63 - 512 and the Perl code generates 
"9223372036854775296.0", which is exact. When the Emacs Lisp reader converts 
this to double it must round since there is no exact double representation, and 
rounding yields 2**63, i.e., 9223372036854775808.0, which is off by 512.

A simple fix is to change the Perl code to omit the trailing ".0", e.g., 
"9223372036854775296" rather than "9223372036854775296.0". This will cause the 
Emacs Lisp reader in master to return an exact integer instead of a float, thus 
avoiding the rounding error. This fix will still suffer from the same rounding 
errors in older Emacs releases where the reader returns a float for integers out 
of fixnum range, but it shouldn't hurt those older releases and it should fix 
the problem in master.

Please see attached patch. I haven't tested or installed the patch as I don't 
use Tramp, but you should be able to test it with something like this:

$ echo '' | dd obs=1 seek=9007199254740992 of=file
0+1 records in
1+0 records out
1 byte (1 B) copied, 0.015429 seconds, 0.1 kB/s
$ ls -l file
-rw-rw-r-- 1 eggert faculty 9007199254740993 2019-08-25 13:28 file

assuming your filesystem supports files containing more than 2**53 bytes - since 
there's a similar bug for file sizes.

> I haven't seen any code in Emacs which needs this slot.

It's used by ede--inode-for-dir, eshell-shuffle-files, ls-lisp-format, 
find-lisp-format, nnmaildir--group-maxnum, nnmaildir--new-number. Typical uses 
are to determine whether two directory entries identify the same file, e.g., 
(equal (file-attribute-inode-number file1) (file-attribute-inode-number file2)) 
or to use it in a hash table.

As I mentioned above, a similar bug occurs for the file size slot: files 
containing more than 2**53 bytes have rounding errors in their sizes. The 
attached patch should fix that too.

[-- Attachment #2: 0001-Fix-Tramp-rounding-of-file-sizes-and-inode-numbers.patch --]
[-- Type: text/x-patch, Size: 1661 bytes --]

From b8242feb8a2b70ce28a72d3976d2c34ce664d0b3 Mon Sep 17 00:00:00 2001
From: Paul Eggert <eggert@cs.ucla.edu>
Date: Sun, 25 Aug 2019 12:27:54 -0700
Subject: [PATCH] Fix Tramp rounding of file sizes and inode numbers

* lisp/net/tramp-sh.el (tramp-perl-file-attributes)
(tramp-perl-directory-files-and-attributes):
Format file sizes and inode numbers with "%u" instead of "%u.0",
to avoid rounding errors when absolute values exceed 2**53
(Bug#36940#94).  This fixes the problem for Emacs 27 and later,
and doesn't hurt in earlier Emacs.
---
 lisp/net/tramp-sh.el | 4 ++--
 1 file changed, 2 insertions(+), 2 deletions(-)

diff --git a/lisp/net/tramp-sh.el b/lisp/net/tramp-sh.el
index 1f7c8f6e49..542bd1c234 100644
--- a/lisp/net/tramp-sh.el
+++ b/lisp/net/tramp-sh.el
@@ -669,7 +669,7 @@ tramp-perl-file-attributes
 $uid = ($ARGV[1] eq \"integer\") ? $stat[4] : \"\\\"\" . getpwuid($stat[4]) . \"\\\"\";
 $gid = ($ARGV[1] eq \"integer\") ? $stat[5] : \"\\\"\" . getgrgid($stat[5]) . \"\\\"\";
 printf(
-    \"(%%s %%u %%s %%s (%%u %%u) (%%u %%u) (%%u %%u) %%u.0 %%u t %%u.0 -1)\\n\",
+    \"(%%s %%u %%s %%s (%%u %%u) (%%u %%u) (%%u %%u) %%u %%u t %%u -1)\\n\",
     $type,
     $stat[3],
     $uid,
@@ -719,7 +719,7 @@ tramp-perl-directory-files-and-attributes
     $gid = ($ARGV[1] eq \"integer\") ? $stat[5] : \"\\\"\" . getgrgid($stat[5]) . \"\\\"\";
     $filename =~ s/\"/\\\\\"/g;
     printf(
-        \"(\\\"%%s\\\" %%s %%u %%s %%s (%%u %%u) (%%u %%u) (%%u %%u) %%u.0 %%u t %%u.0 -1)\\n\",
+        \"(\\\"%%s\\\" %%s %%u %%s %%s (%%u %%u) (%%u %%u) (%%u %%u) %%u %%u t %%u -1)\\n\",
         $filename,
         $type,
         $stat[3],
-- 
2.17.1

bug#36940: tests slowness and failure after recent Tramp changes

[Michael Albinus]

Paul Eggert <eggert@cs.ucla.edu> writes:

Hi Paul,

> For example, suppose the inode number is 2**63 - 512 and the Perl code
> generates "9223372036854775296.0", which is exact. When the Emacs Lisp
> reader converts this to double it must round since there is no exact
> double representation, and rounding yields 2**63, i.e.,
> 9223372036854775808.0, which is off by 512.
>
> A simple fix is to change the Perl code to omit the trailing ".0",
> e.g., "9223372036854775296" rather than "9223372036854775296.0". This
> will cause the Emacs Lisp reader in master to return an exact integer
> instead of a float, thus avoiding the rounding error. This fix will
> still suffer from the same rounding errors in older Emacs releases
> where the reader returns a float for integers out of fixnum range, but
> it shouldn't hurt those older releases and it should fix the problem
> in master.

Indeed, up to Emacs 26 this rounding error still applies. With master
(improved big number support) it works fine.

> Please see attached patch. I haven't tested or installed the patch as
> I don't use Tramp, but you should be able to test it with something
> like this:

OK for me. You might install the patch, and also adapt the templates in
`tramp-do-file-attributes-with-stat and'
`tramp-do-directory-files-and-attributes-with-stat'.

>> I haven't seen any code in Emacs which needs this slot.
>
> It's used by ede--inode-for-dir, eshell-shuffle-files, ls-lisp-format,
> find-lisp-format, nnmaildir--group-maxnum,
> nnmaildir--new-number.

`ls-lisp-format' and `find-lisp-format' don't count, they *provide* the
inode number; they don't *use* it.

> Typical uses are to determine whether two
> directory entries identify the same file, e.g., (equal
> (file-attribute-inode-number file1) (file-attribute-inode-number
> file2)) or to use it in a hash table.

`ede--inode-for-dir' and `nnmaildir--*' are a little bit lazy, they
don't compare the device number. Might be acceptable; one could assume
that a project dir or a mail dir handle only files on the same file system.

Best regards, Michael.

bug#36940: tests slowness and failure after recent Tramp changes

[Paul Eggert]

[-- Attachment #1: Type: text/plain, Size: 294 bytes --]

Michael Albinus wrote:
> You might install the patch, and also adapt the templates in
> `tramp-do-file-attributes-with-stat and'
> `tramp-do-directory-files-and-attributes-with-stat'.

Thanks, I missed those templates. I adapted them too and installed the attached 
combined patch into master.

[-- Attachment #2: 0001-Fix-Tramp-rounding-of-file-sizes-and-inode-numbers.patch --]
[-- Type: text/x-patch, Size: 2732 bytes --]

From 0e2d559daf43a04024ceaacfc8844839af2d50df Mon Sep 17 00:00:00 2001
From: Paul Eggert <eggert@cs.ucla.edu>
Date: Mon, 26 Aug 2019 18:57:56 -0700
Subject: [PATCH] Fix Tramp rounding of file sizes and inode numbers

* lisp/net/tramp-sh.el (tramp-perl-file-attributes)
(tramp-perl-directory-files-and-attributes)
(tramp-do-file-attributes-with-stat)
(tramp-do-directory-files-and-attributes-with-stat):
Format file sizes and inode numbers without trailing ".0",
to avoid rounding errors when absolute values exceed 2**53
(Bug#36940#94).  This fixes the problem for Emacs 27 and later,
and doesn't hurt in earlier Emacs.
---
 lisp/net/tramp-sh.el | 8 ++++----
 1 file changed, 4 insertions(+), 4 deletions(-)

diff --git a/lisp/net/tramp-sh.el b/lisp/net/tramp-sh.el
index 1f7c8f6e49..217e73a24b 100644
--- a/lisp/net/tramp-sh.el
+++ b/lisp/net/tramp-sh.el
@@ -669,7 +669,7 @@ tramp-perl-file-attributes
 $uid = ($ARGV[1] eq \"integer\") ? $stat[4] : \"\\\"\" . getpwuid($stat[4]) . \"\\\"\";
 $gid = ($ARGV[1] eq \"integer\") ? $stat[5] : \"\\\"\" . getgrgid($stat[5]) . \"\\\"\";
 printf(
-    \"(%%s %%u %%s %%s (%%u %%u) (%%u %%u) (%%u %%u) %%u.0 %%u t %%u.0 -1)\\n\",
+    \"(%%s %%u %%s %%s (%%u %%u) (%%u %%u) (%%u %%u) %%u %%u t %%u -1)\\n\",
     $type,
     $stat[3],
     $uid,
@@ -719,7 +719,7 @@ tramp-perl-directory-files-and-attributes
     $gid = ($ARGV[1] eq \"integer\") ? $stat[5] : \"\\\"\" . getgrgid($stat[5]) . \"\\\"\";
     $filename =~ s/\"/\\\\\"/g;
     printf(
-        \"(\\\"%%s\\\" %%s %%u %%s %%s (%%u %%u) (%%u %%u) (%%u %%u) %%u.0 %%u t %%u.0 -1)\\n\",
+        \"(\\\"%%s\\\" %%s %%u %%s %%s (%%u %%u) (%%u %%u) (%%u %%u) %%u %%u t %%u -1)\\n\",
         $filename,
         $type,
         $stat[3],
@@ -1353,7 +1353,7 @@ tramp-do-file-attributes-with-stat
        ;; `tramp-stat-marker', in order to make a proper shell escape
        ;; of them in file names.
        "( (%s %s || %s -h %s) && (%s -c "
-       "'((%s%%N%s) %%h %s %s %%X %%Y %%Z %%s.0 %s%%A%s t %%i.0 -1)' "
+       "'((%s%%N%s) %%h %s %s %%X %%Y %%Z %%s %s%%A%s t %%i -1)' "
        "%s | sed -e 's/\"/\\\\\"/g' -e 's/%s/\"/g') || echo nil)"))
     (tramp-get-file-exists-command vec)
     (tramp-shell-quote-argument localname)
@@ -1764,7 +1764,7 @@ tramp-do-directory-files-and-attributes-with-stat
        ;; of them in file names.
        "cd %s && echo \"(\"; (%s %s -a | "
        "xargs %s -c "
-       "'(%s%%n%s (%s%%N%s) %%h %s %s %%X %%Y %%Z %%s.0 %s%%A%s t %%i.0 -1)' "
+       "'(%s%%n%s (%s%%N%s) %%h %s %s %%X %%Y %%Z %%s %s%%A%s t %%i -1)' "
        "-- 2>/dev/null | sed -e 's/\"/\\\\\"/g' -e 's/%s/\"/g'); echo \")\""))
     (tramp-shell-quote-argument localname)
     (tramp-get-ls-command vec)
-- 
2.17.1

bug#36940: tests slowness and failure after recent Tramp changes

[Michael Albinus]

Michael Albinus <michael.albinus@gmx.de> writes:

Hi Stefan,

> If you want to get a log file when running tests for package FOO, say
> "make FOO.log". This seems to be broken; will check.

Fixed in master. You can run "make tramp-tests.log" now, for example.

Best regards, Michael.