bug#42538: 28.0.50; tramp-test35-remote-path test timing out on macOS

classic Classic list List threaded Threaded
22 messages Options
12
Reply | Threaded
Open this post in threaded view
|

bug#42538: 28.0.50; tramp-test35-remote-path test timing out on macOS

Philipp Stephani

This is another follow-up to Bug#30700.  This time a specific TRAMP test
times out on macOS:

$ timeout -v 30m make -C test lisp/net/tramp-tests SELECTOR=tramp-test35-remote-path
  GEN      lisp/net/tramp-tests.log
Running 1 tests (2020-07-25 20:28:58+0200, selector `tramp-test35-remote-path')
timeout: sending signal TERM to command ‘make’
make[1]: *** [lisp/net/tramp-tests.log] Terminated: 15
make: *** [lisp/net/tramp-tests] Terminated: 15



In GNU Emacs 28.0.50 (build 67, x86_64-apple-darwin19.5.0, NS appkit-1894.50 Version 10.15.5 (Build 19F101))
 of 2020-07-25
Repository revision: 3b44829823f43d3736b8ec9db2258eeff7f6c16a
Repository branch: master
Windowing system distributor 'Apple', version 10.3.1894
System Description:  Mac OS X 10.15.5

Recent messages:
For information about GNU Emacs and the GNU system, type C-h C-a.

Configured using:
 'configure --with-modules --without-xml2 --without-pop --with-mailutils
 --enable-gcc-warnings=warn-only --enable-checking=all
 --enable-check-lisp-object-type 'CFLAGS=-ggdb3 -O0''

Configured features:
JPEG TIFF GIF PNG NOTIFY KQUEUE ACL GNUTLS ZLIB TOOLKIT_SCROLL_BARS NS
MODULES THREADS JSON PDUMPER LCMS2

Important settings:
  value of $LANG: de_DE.UTF-8
  locale-coding-system: utf-8-unix

Major mode: Lisp Interaction

Minor modes in effect:
  tooltip-mode: t
  global-eldoc-mode: t
  eldoc-mode: t
  electric-indent-mode: t
  mouse-wheel-mode: t
  tool-bar-mode: t
  menu-bar-mode: t
  file-name-shadow-mode: t
  global-font-lock-mode: t
  font-lock-mode: t
  blink-cursor-mode: t
  auto-composition-mode: t
  auto-encryption-mode: t
  auto-compression-mode: t
  line-number-mode: t
  transient-mark-mode: t

Load-path shadows:
None found.

Features:
(shadow sort mail-extr emacsbug message rmc dired dired-loaddefs rfc822
mml easymenu mml-sec epa epg epg-config gnus-util rmail rmail-loaddefs
text-property-search mm-decode mm-bodies mm-encode mail-parse rfc2231
mailabbrev gmm-utils mailheader sendmail rfc2047 rfc2045 ietf-drums
mm-util mail-prsvr mail-utils time-date phst skeleton derived edmacro
kmacro pcase ffap thingatpt url url-proxy url-privacy url-expand
url-methods url-history url-cookie url-domsuf url-util url-parse
auth-source cl-seq eieio eieio-core cl-macs eieio-loaddefs
password-cache json map url-vars mailcap subr-x rx gnutls puny seq
byte-opt gv bytecomp byte-compile cconv dbus xml compile comint
ansi-color ring cl-loaddefs cl-lib tooltip eldoc electric uniquify
ediff-hook vc-hooks lisp-float-type mwheel term/ns-win ns-win
ucs-normalize mule-util term/common-win tool-bar dnd fontset image
regexp-opt fringe tabulated-list replace newcomment text-mode elisp-mode
lisp-mode prog-mode register page tab-bar menu-bar rfn-eshadow isearch
timer select scroll-bar mouse jit-lock font-lock syntax facemenu
font-core term/tty-colors frame minibuffer cl-generic cham georgian
utf-8-lang misc-lang vietnamese tibetan thai tai-viet lao korean
japanese eucjp-ms cp51932 hebrew greek romanian slovak czech european
ethiopic indian cyrillic chinese composite charscript charprop
case-table epa-hook jka-cmpr-hook help simple abbrev obarray
cl-preloaded nadvice loaddefs button faces cus-face macroexp files
text-properties overlay sha1 md5 base64 format env code-pages mule
custom widget hashtable-print-readable backquote threads kqueue cocoa ns
lcms2 multi-tty make-network-process emacs)

Memory information:
((conses 16 69784 6183)
 (symbols 48 8650 1)
 (strings 32 23544 1597)
 (string-bytes 1 768670)
 (vectors 16 14151)
 (vector-slots 8 172559 7527)
 (floats 8 26 29)
 (intervals 56 206 0)
 (buffers 992 10))



Reply | Threaded
Open this post in threaded view
|

bug#42538: 28.0.50; tramp-test35-remote-path test timing out on macOS

Michael Albinus
Philipp <[hidden email]> writes:

Hi Philipp,

> This is another follow-up to Bug#30700.  This time a specific TRAMP test
> times out on macOS:
>
> $ timeout -v 30m make -C test lisp/net/tramp-tests SELECTOR=tramp-test35-remote-path
>   GEN      lisp/net/tramp-tests.log
> Running 1 tests (2020-07-25 20:28:58+0200, selector `tramp-test35-remote-path')
> timeout: sending signal TERM to command ‘make’
> make[1]: *** [lisp/net/tramp-tests.log] Terminated: 15
> make: *** [lisp/net/tramp-tests] Terminated: 15

Well, I don't run macOS, so I cannot reproduce.

Could you please apply the appended patch to tramp-tests.el? Then run

$ rm test/lisp/net/tramp-tests.log
$ timeout -v 30s make -C test lisp/net/tramp-tests.log SELECTOR=tramp-test35-remote-path

This generates the file tramp-tests.log, which I would like to
see. Likely, it is huge, so pls send it directly to me.

I have also shortened the timeout to 30s; usually the test runs a
second, or two.

Best rewgards, Michael.


attachment0 (922 bytes) Download Attachment
Reply | Threaded
Open this post in threaded view
|

bug#42538: 28.0.50; tramp-test35-remote-path test timing out on macOS

Philipp Stephani
Am So., 26. Juli 2020 um 11:19 Uhr schrieb Michael Albinus
<[hidden email]>:

>
> Philipp <[hidden email]> writes:
>
> Hi Philipp,
>
> > This is another follow-up to Bug#30700.  This time a specific TRAMP test
> > times out on macOS:
> >
> > $ timeout -v 30m make -C test lisp/net/tramp-tests SELECTOR=tramp-test35-remote-path
> >   GEN      lisp/net/tramp-tests.log
> > Running 1 tests (2020-07-25 20:28:58+0200, selector `tramp-test35-remote-path')
> > timeout: sending signal TERM to command ‘make’
> > make[1]: *** [lisp/net/tramp-tests.log] Terminated: 15
> > make: *** [lisp/net/tramp-tests] Terminated: 15
>
> Well, I don't run macOS, so I cannot reproduce.
>
> Could you please apply the appended patch to tramp-tests.el? Then run
>
> $ rm test/lisp/net/tramp-tests.log
> $ timeout -v 30s make -C test lisp/net/tramp-tests.log SELECTOR=tramp-test35-remote-path
>
> This generates the file tramp-tests.log, which I would like to
> see. Likely, it is huge, so pls send it directly to me.

In fact, it doesn't exist because the test is killed before it can
write the file :-)

Here's a slightly modified invocation plus output:

$ timeout -v 5m make -C test lisp/net/tramp-tests.log
SELECTOR=tramp-test35-remote-path WRITE_LOG=' 2>&1 | tee $@' V=1
/usr/local/bin/gmkdir -p lisp/net/
HOME=/nonexistent EMACSLOADPATH= LC_ALL=C
EMACS_TEST_DIRECTORY=/Users/p/Entwicklung/Emacs/master/test
"../src/emacs" --module-assertions --no-init-file --no-site-file
--no-site-lisp -L ":."  \
  -l ert  -l lisp/net/tramp-tests.el \
  --batch --eval '(ert-run-tests-batch-and-exit (quote
tramp-test35-remote-path))' 2>&1 | tee lisp/net/tramp-tests.log
Running 1 tests (2020-07-26 16:04:54+0200, selector `tramp-test35-remote-path')
Tramp: Sending command `exec sh -i'
Tramp: Found remote shell prompt on `p'
Tramp: Sending command `exec sh -i'
Tramp: Found remote shell prompt on `p'
Tramp: Sending command `exec sh -i'
Tramp: Found remote shell prompt on `p'
Tramp: Sending command `exec sh -i'
Tramp: Found remote shell prompt on `p'
timeout: sending signal TERM to command ‘make’
make: *** [lisp/net/tramp-tests.log] Terminated: 15


That is, the test starts to make some progress and then hangs.



Reply | Threaded
Open this post in threaded view
|

bug#42538: 28.0.50; tramp-test35-remote-path test timing out on macOS

Michael Albinus
Philipp Stephani <[hidden email]> writes:

Hi Philipp,

>> Could you please apply the appended patch to tramp-tests.el? Then run
>>
>> $ rm test/lisp/net/tramp-tests.log
>> $ timeout -v 30s make -C test lisp/net/tramp-tests.log
>> SELECTOR=tramp-test35-remote-path
>>
>> This generates the file tramp-tests.log, which I would like to
>> see. Likely, it is huge, so pls send it directly to me.
>
> In fact, it doesn't exist because the test is killed before it can
> write the file :-)
Indeed. So I've modified the patch; the test case commits suicide after
30 seconds. You can call it simply by

$ rm test/lisp/net/tramp-tests.log
$ make -C test lisp/net/tramp-tests.log SELECTOR=tramp-test35-remote-path

> Here's a slightly modified invocation plus output:
>
> That is, the test starts to make some progress and then hangs.

Thanks, but this misses the log I need for analysis ...

Best regards, Michael.


attachment0 (976 bytes) Download Attachment
Reply | Threaded
Open this post in threaded view
|

bug#42538: 28.0.50; tramp-test35-remote-path test timing out on macOS

Philipp Stephani
Am So., 26. Juli 2020 um 17:52 Uhr schrieb Michael Albinus
<[hidden email]>:

>
> Philipp Stephani <[hidden email]> writes:
>
> Hi Philipp,
>
> >> Could you please apply the appended patch to tramp-tests.el? Then run
> >>
> >> $ rm test/lisp/net/tramp-tests.log
> >> $ timeout -v 30s make -C test lisp/net/tramp-tests.log
> >> SELECTOR=tramp-test35-remote-path
> >>
> >> This generates the file tramp-tests.log, which I would like to
> >> see. Likely, it is huge, so pls send it directly to me.
> >
> > In fact, it doesn't exist because the test is killed before it can
> > write the file :-)
>
> Indeed. So I've modified the patch; the test case commits suicide after
> 30 seconds. You can call it simply by
>
> $ rm test/lisp/net/tramp-tests.log
> $ make -C test lisp/net/tramp-tests.log SELECTOR=tramp-test35-remote-path

OK, I've attached the log file now. (It's not that large.)

tramp-tests.log (261K) Download Attachment
Reply | Threaded
Open this post in threaded view
|

bug#42538: 28.0.50; tramp-test35-remote-path test timing out on macOS

Michael Albinus
Philipp Stephani <[hidden email]> writes:

Hi Philipp,

>> Indeed. So I've modified the patch; the test case commits suicide after
>> 30 seconds. You can call it simply by
>>
>> $ rm test/lisp/net/tramp-tests.log
>> $ make -C test lisp/net/tramp-tests.log SELECTOR=tramp-test35-remote-path
>
>
> OK, I've attached the log file now. (It's not that large.)

And it tells us The Truth (TM).

Under macOS, PIPE_BUF is very short:

--8<---------------cut here---------------start------------->8---
23:33:50.197963 tramp-send-command (6) # getconf PIPE_BUF / 2>/dev/null || echo 4096 2>/dev/null; echo tramp_exit_status $?
23:33:50.200794 tramp-wait-for-regexp (6) #
512
tramp_exit_status 0
///ec22873252400ed5da2786d09e65ca05#$
--8<---------------cut here---------------end--------------->8---

Tramp tries to set a very long PATH variable (this is the essence of the
test), creating a temp file via a heredoc command. With other OSes, this
trick works. But it refuses to work for you:

--8<---------------cut here---------------start------------->8---
23:34:00.273274 tramp-send-command (6) # cat >/tmp/tramp.21cf9w <<'ee34a56d9cb9cbd177c29dcaca509be9'
PATH=/usr/bin:/bin:/usr/sbin:/sbin:/usr/local/bin:/usr/local/sbin:/var/folders/ks/sxl3n3w51td0ry21j3tjs1wh0000gn/T/tramp-test16h5Wh/XBjC1b:/var/folders/ks/sxl3n3w51td0ry21j3tjs1wh0000gn/T/tramp-test16h5Wh/C2Xb3Q:/var/folders/ks/sxl3n3w51td0ry21j3tjs1wh0000gn/T/tramp-test16h5Wh/oUW8Hk:/var/folders/ks/sxl3n3w51td0ry21j3tjs1wh0000gn/T/tramp-test16h5Wh/nmtc9J:/var/folders/ks/sxl3n3w51td0ry21j3tjs1wh0000gn/T/tramp-test16h5Wh/H6S488:/var/folders/ks/sxl3n3w51td0ry21j3tjs1wh0000gn/T/tramp-test16h5Wh/BMJQL7:/var/folders/ks/sxl3n3w51td0ry21j3tjs1wh0000gn/T/tramp-test16h5Wh/4mZhx7:/var/folders/ks/sxl3n3w51td0ry21j3tjs1wh0000gn/T/tramp-test16h5Wh/1HY100:/var/folders/ks/sxl3n3w51td0ry21j3tjs1wh0000gn/T/tramp-test16h5Wh/Nu1cnQ:/var/folders/ks/sxl3n3w51td0ry21j3tjs1wh0000gn/T/tramp-test16h5Wh/r17vPP:/var/folders/ks/sxl3n3w51td0ry21j3tjs1wh0000gn/T/tramp-test16h5Wh/AuhHIQ:/var/folders/ks/sxl3n3w51td0ry21j3tjs1wh0000gn/T/tramp-test16h5Wh/0o1mE1:/var/folders/ks/sxl3n3w51td0ry21j3tjs1wh0000gn/T/tramp-test16h5Wh/Z4O5Sx:/var/folders/ks/sxl3n3w51td0ry21j3tjs1wh0000gn/T/tramp-test16h5Wh/46Q1L2:/var/folders/ks/sxl3n3w51td0ry21j3tjs1wh0000gn/T/tramp-test16h5Wh/WjjoRH:/var/folders/ks/sxl3n3w51td0ry21j3tjs1wh0000gn/T/tramp-test16h5Wh/CBgDaw:/var/folders/ks/sxl3n3w51td0ry21j3tjs1wh0000gn/T/tramp-test16h5Wh/j1IF30:/var/folders/ks/sxl3n3w51td0ry21j3tjs1wh0000gn/T/tramp-test16h5Wh/o3WfTs:/var/folders/ks/sxl3n3w51td0ry21j3tjs1wh0000gn/T/tramp-test16h5Wh/EsFexA:/var/folders/ks/sxl3n3w51td0ry21j3tjs1wh0000gn/T/tramp-test16h5Wh/SUmpMi:/var/folders/ks/sxl3n3w51td0ry21j3tjs1wh0000gn/T/tramp-test16h5Wh/vEA9uL:/var/folders/ks/sxl3n3w51td0ry21j3tjs1wh0000gn/T/tramp-test16h5Wh/A3Z06C:/var/folders/ks/sxl3n3w51td0ry21j3tjs1wh0000gn/T/tramp-test16h5Wh/j3TEeY:/var/folders/ks/sxl3n3w51td0ry21j3tjs1wh0000gn/T/tramp-test16h5Wh/1Zm9fA:/var/folders/ks/sxl3n3w51td0ry21j3tjs1wh0000gn/T/tramp-test16h5Wh/eLdpLh:/var/folders/ks/sxl3n3w51td0ry21j3tjs1wh0000gn/T/tramp-test16h5Wh/rF4Bxu:/var/folders/ks/sxl3n3w51td0ry21j3tjs1wh0000gn/T/tramp-test16h5Wh/5xWpeg:/var/folders/ks/sxl3n3w51td0ry21j3tjs1wh0000gn/T/tramp-test16h5Wh/nbZeG4:/var/folders/ks/sxl3n3w51td0ry21j3tjs1wh0000gn/T/tramp-test16h5Wh/77cnPb:/var/folders/ks/sxl3n3w51td0ry21j3tjs1wh0000gn/T/tramp-test16h5Wh/up7DIK:/var/folders/ks/sxl3n3w51td0ry21j3tjs1wh0000gn/T/tramp-test16h5Wh/lLTfv4:/var/folders/ks/sxl3n3w51td0ry21j3tjs1wh0000gn/T/tramp-test16h5Wh/0NUphe:/var/folders/ks/sxl3n3w51td0ry21j3tjs1wh0000gn/T/tramp-test16h5Wh/g2GVE8:/var/folders/ks/sxl3n3w51td0ry21j3tjs1wh0000gn/T/tramp-test16h5Wh/ha6g1W:/var/folders/ks/sxl3n3w51td0ry21j3tjs1wh0000gn/T/tramp-test16h5Wh/uZMI15:/var/folders/ks/sxl3n3w51td0ry21j3tjs1wh0000gn/T/tramp-test16h5Wh/n7F9Zr:/var/folders/ks/sxl3n3w51td0ry21j3tjs1wh0000gn/T/tramp-test16h5Wh/iRvb2d:/var/folders/ks/sxl3n3w51td0ry21j3tjs1wh0000gn/T/tramp-test16h5Wh/7NpjgT:/var/folders/ks/sxl3n3w51td0ry21j3tjs1wh0000gn/T/tramp-test16h5Wh/GLF9LB:/var/folders/ks/sxl3n3w51td0ry21j3tjs1wh0000gn/T/tramp-test16h5Wh/0vY43M:/var/folders/ks/sxl3n3w51td0ry21j3tjs1wh0000gn/T/tramp-test16h5Wh/Jz1jEI:/var/folders/ks/sxl3n3w51td0ry21j3tjs1wh0000gn/T/tramp-test16h5Wh/4SqFP3:/var/folders/ks/sxl3n3w51td0ry21j3tjs1wh0000gn/T/tramp-test16h5Wh/wlgvgt:/var/folders/ks/sxl3n3w51td0ry21j3tjs1wh0000gn/T/tramp-test16h5Wh/68tScv:/var/folders/ks/sxl3n3w51td0ry21j3tjs1wh0000gn/T/tramp-test16h5Wh/LmWqYP:/var/folders/ks/sxl3n3w51td0ry21j3tjs1wh0000gn/T/tramp-test16h5Wh/2UbEme:/var/folders/ks/sxl3n3w51td0ry21j3tjs1wh0000gn/T/tramp-test16h5Wh/29SifB:/var/folders/ks/sxl3n3w51td0ry21j3tjs1wh0000gn/T/tramp-test16h5Wh/8388Ha:/var/folders/ks/sxl3n3w51td0ry21j3tjs1wh0000gn/T/tramp-test16h5Wh/sEve50:/var/folders/ks/sxl3n3w51td0ry21j3tjs1wh0000gn/T/tramp-test16h5Wh/ofutHX:/var/folders/ks/sxl3n3w51td0ry21j3tjs1wh0000gn/T/tramp-test16h5Wh/jOEMm0:/var/folders/ks/sxl3n3w51td0ry21j3tjs1wh0000gn/T/tramp-test16h5Wh/0laQB5:/var/folders/ks/sxl3n3w51td0ry21j3tjs1wh0000gn/T/tramp-test16h5Wh/UWDANC:/var/folders/ks/sxl3n3w51td0ry21j3tjs1wh0000gn/T/tramp-test16h5Wh/gke4IJ:/var/folders/ks/sxl3n3w51td0ry21j3tjs1wh0000gn/T/tramp-test16h5Wh/GBuhLz:/var/folders/ks/sxl3n3w51td0ry21j3tjs1wh0000gn/T/tramp-test16h5Wh/gWiUYZ:/var/folders/ks/sxl3n3w51td0ry21j3tjs1wh0000gn/T/tramp-test16h5Wh/DxLjh8:/var/folders/ks/sxl3n3w51td0ry21j3tjs1wh0000gn/T/tramp-test16h5Wh/EeeqZI:/var/folders/ks/sxl3n3w51td0ry21j3tjs1wh0000gn/T/tramp-test16h5Wh/rF99jV:/var/folders/ks/sxl3n3w51td0ry21j3tjs1wh0000gn/T/tramp-test16h5Wh/e0OVZR:/var/folders/ks/sxl3n3w51td0ry21j3tjs1wh0000gn/T/tramp-test16h5Wh/aDrXdX:/var/folders/ks/sxl3n3w51td0ry21j3tjs1wh0000gn/T/tramp-test16h5Wh/m0a6et:/var/folders/ks/sxl3n3w51td0ry21j3tjs1wh0000gn/T/tramp-test16h5Wh/po8aFp:/var/folders/ks/sxl3n3w51td0ry21j3tjs1wh0000gn/T/tramp-test16h5Wh/RFMSih:/var/folders/ks/sxl3n3w51td0ry21j3tjs1wh0000gn/T/tramp-test16h5Wh/W01RNs:/var/folders/ks/sxl3n3w51td0ry21j3tjs1wh0000gn/T/tramp-test16h5Wh/hVC19w:/var/folders/ks/sxl3n3w51td0ry21j3tjs1wh0000gn/T/tramp-test16h5Wh/muGaOz; export PATH
ee34a56d9cb9cbd177c29dcaca509be9
23:34:19.714146 tramp-process-sentinel (5) # Sentinel called: `#<process *tramp/mock p*>' `killed: 9
'
--8<---------------cut here---------------end--------------->8---

As you see, Tramp is stalled for 19 seconds, and then the timeout kills
it. I will see whether I could rearrange the command sequence. Maybe
writing the temp file just in shorter chunks, or so.

Best regards, Michael.



Reply | Threaded
Open this post in threaded view
|

bug#42538: 28.0.50; tramp-test35-remote-path test timing out on macOS

Michael Albinus
Michael Albinus <[hidden email]> writes:

Hi Philipp,

> As you see, Tramp is stalled for 19 seconds, and then the timeout kills
> it. I will see whether I could rearrange the command sequence. Maybe
> writing the temp file just in shorter chunks, or so.

Could you pls check, whether the appended patch works for you?

Thanks, and best regards, Michael.


attachment0 (2K) Download Attachment
Reply | Threaded
Open this post in threaded view
|

bug#42538: 28.0.50; tramp-test35-remote-path test timing out on macOS

Philipp Stephani
Am Mi., 29. Juli 2020 um 16:26 Uhr schrieb Michael Albinus
<[hidden email]>:

>
> Michael Albinus <[hidden email]> writes:
>
> Hi Philipp,
>
> > As you see, Tramp is stalled for 19 seconds, and then the timeout kills
> > it. I will see whether I could rearrange the command sequence. Maybe
> > writing the temp file just in shorter chunks, or so.
>
> Could you pls check, whether the appended patch works for you?
>


Thanks, that appears to work, at least the test now finishes
successfully within 13 seconds.

However, now it looks like tramp-test29-start-file-process is timing out...



Reply | Threaded
Open this post in threaded view
|

bug#42538: 28.0.50; tramp-test35-remote-path test timing out on macOS

Michael Albinus
Philipp Stephani <[hidden email]> writes:

Hi Philipp,

>> > As you see, Tramp is stalled for 19 seconds, and then the timeout kills
>> > it. I will see whether I could rearrange the command sequence. Maybe
>> > writing the temp file just in shorter chunks, or so.
>>
>> Could you pls check, whether the appended patch works for you?
>
> Thanks, that appears to work, at least the test now finishes
> successfully within 13 seconds.

OK, so I've pushed the patch to the master branch. It will also be
merged into the emacs-27 branch after the release of 27.1.

> However, now it looks like tramp-test29-start-file-process is timing out...

Strange. The patch doesn't touch anything which is relevant for
tramp-test29-start-file-process, AFAICT. OK, same procedure as very
year: apply the appended patch to tramp-tests.el, and rerun the
test. The debug buffer shall tell us more.

Best regards, Michael.


attachment0 (1K) Download Attachment
Reply | Threaded
Open this post in threaded view
|

bug#42538: 28.0.50; tramp-test35-remote-path test timing out on macOS

Philipp Stephani
Am Do., 30. Juli 2020 um 13:53 Uhr schrieb Michael Albinus
<[hidden email]>:

>
> Philipp Stephani <[hidden email]> writes:
>
> Hi Philipp,
>
> >> > As you see, Tramp is stalled for 19 seconds, and then the timeout kills
> >> > it. I will see whether I could rearrange the command sequence. Maybe
> >> > writing the temp file just in shorter chunks, or so.
> >>
> >> Could you pls check, whether the appended patch works for you?
> >
> > Thanks, that appears to work, at least the test now finishes
> > successfully within 13 seconds.
>
> OK, so I've pushed the patch to the master branch. It will also be
> merged into the emacs-27 branch after the release of 27.1.

Thanks!

>
> > However, now it looks like tramp-test29-start-file-process is timing out...
>
> Strange. The patch doesn't touch anything which is relevant for
> tramp-test29-start-file-process, AFAICT. OK, same procedure as very
> year: apply the appended patch to tramp-tests.el, and rerun the
> test. The debug buffer shall tell us more.
>


An update on this: I messed up the test numbers, it's actually the
test tramp-test28-process-file that times out. I've tried to apply a
similar patch (increasing the log level and using with-timeout), but
apparently it's stuck enough that none of the signals except SIGKILL
work any more. Here's the console output:

HOME=/nonexistent EMACSLOADPATH= LC_ALL=C
EMACS_TEST_DIRECTORY=/Users/p/Entwicklung/Emacs/master/test
"../src/emacs" --module-assertions --no-init-file --no-site-file
--no-site-lisp -L ":."  \
  -l ert  -l lisp/net/tramp-tests.el \
  --batch --eval '(ert-run-tests-batch-and-exit (quote
tramp-test28-process-file))'
Running 1 tests (2020-07-31 16:09:42+0200, selector `tramp-test28-process-file')
Tramp: Sending command `exec sh -i'
Tramp: Found remote shell prompt on `p'
timeout: sending signal TERM to command ‘make’

^Ctimeout: sending signal INT to command ‘make’
^\timeout: sending signal QUIT to command ‘make’

make[1]: *** [lisp/net/tramp-tests.log] Killed: 9
make: *** [lisp/net/tramp-tests] Quit: 3



Reply | Threaded
Open this post in threaded view
|

bug#42538: 28.0.50; tramp-test35-remote-path test timing out on macOS

Michael Albinus
Philipp Stephani <[hidden email]> writes:

Hi Philipp,

>> HOME=/nonexistent EMACSLOADPATH= LC_ALL=C
>> EMACS_TEST_DIRECTORY=/Users/p/Entwicklung/Emacs/master/test
>> "../src/emacs" --module-assertions --no-init-file --no-site-file
>> --no-site-lisp -L ":."  \
>>   -l ert  -l lisp/net/tramp-tests.el \
>>   --batch --eval '(ert-run-tests-batch-and-exit (quote
>> tramp-test28-process-file))'
>> Running 1 tests (2020-07-31 16:09:42+0200, selector `tramp-test28-process-file')
>> Tramp: Sending command `exec sh -i'
>> Tramp: Found remote shell prompt on `p'
>> timeout: sending signal TERM to command ‘make’
>>
>> ^Ctimeout: sending signal INT to command ‘make’
>> ^\timeout: sending signal QUIT to command ‘make’
>>
>> make[1]: *** [lisp/net/tramp-tests.log] Killed: 9
>> make: *** [lisp/net/tramp-tests] Quit: 3
>
> Emacs here is stuck waiting for the process "bash -c 'kill -17 $$'" to
> terminate. However, signal 17 is SIGSTOP on macOS, so this process can
> never terminate. This might be caused by the code in
> `tramp-get-signal-strings' assuming that signal 19 is SIGSTOP.

Thanks for the analysis. However, I fail to see where Tramp fires the
command 'kill -17 $$'. There's only 'kill -2 $$'. Could you, please, show me?

Best regards, Michael.



Reply | Threaded
Open this post in threaded view
|

bug#42538: 28.0.50; tramp-test35-remote-path test timing out on macOS

Philipp Stephani
Am Fr., 31. Juli 2020 um 18:55 Uhr schrieb Michael Albinus
<[hidden email]>:

>
> Philipp Stephani <[hidden email]> writes:
>
> Hi Philipp,
>
> >> HOME=/nonexistent EMACSLOADPATH= LC_ALL=C
> >> EMACS_TEST_DIRECTORY=/Users/p/Entwicklung/Emacs/master/test
> >> "../src/emacs" --module-assertions --no-init-file --no-site-file
> >> --no-site-lisp -L ":."  \
> >>   -l ert  -l lisp/net/tramp-tests.el \
> >>   --batch --eval '(ert-run-tests-batch-and-exit (quote
> >> tramp-test28-process-file))'
> >> Running 1 tests (2020-07-31 16:09:42+0200, selector `tramp-test28-process-file')
> >> Tramp: Sending command `exec sh -i'
> >> Tramp: Found remote shell prompt on `p'
> >> timeout: sending signal TERM to command ‘make’
> >>
> >> ^Ctimeout: sending signal INT to command ‘make’
> >> ^\timeout: sending signal QUIT to command ‘make’
> >>
> >> make[1]: *** [lisp/net/tramp-tests.log] Killed: 9
> >> make: *** [lisp/net/tramp-tests] Quit: 3
> >
> > Emacs here is stuck waiting for the process "bash -c 'kill -17 $$'" to
> > terminate. However, signal 17 is SIGSTOP on macOS, so this process can
> > never terminate. This might be caused by the code in
> > `tramp-get-signal-strings' assuming that signal 19 is SIGSTOP.
>
> Thanks for the analysis. However, I fail to see where Tramp fires the
> command 'kill -17 $$'. There's only 'kill -2 $$'. Could you, please, show me?

`tramp-get-signal-strings' invokes "bash -c 'kill -NUM $$'" for all
signal numbers, including 17. It excluded 19, assuming that's SIGSTOP,
but that assumption doesn't hold on macOS (or FreeBSD, or any non-x86
system, FWIW).



Reply | Threaded
Open this post in threaded view
|

bug#42538: 28.0.50; tramp-test35-remote-path test timing out on macOS

Michael Albinus
Philipp Stephani <[hidden email]> writes:

Hi Philipp,

>> Thanks for the analysis. However, I fail to see where Tramp fires the
>> command 'kill -17 $$'. There's only 'kill -2 $$'. Could you, please, show me?
>
> `tramp-get-signal-strings' invokes "bash -c 'kill -NUM $$'" for all
> signal numbers, including 17. It excluded 19, assuming that's SIGSTOP,
> but that assumption doesn't hold on macOS (or FreeBSD, or any non-x86
> system, FWIW).

I see. `tramp-get-signal-strings' is problematic anyway, because it runs
locally, but shall serve the signal strings for the remote host. Maybe,
we shall assume standardized signal strings up to 15 only.

What happens, if you replace the function by (untested)

--8<---------------cut here---------------start------------->8---
(defun tramp-get-signal-strings ()
  "Strings to return by `process-file' in case of signals."
  ;; We use key nil for local connection properties.
  (with-tramp-connection-property nil "signal-strings"
    (let (result)
      (dotimes (i 128)
        (push
         (if (and (< i 16)
                  (stringp shell-file-name) (executable-find shell-file-name))
             (call-process
              shell-file-name nil nil nil "-c" (format "kill -%d $$" i))
           (format "Signal %d" i))
         result))
      ;; Due to Bug#41287, we cannot add this to the `dotimes' clause.
      (reverse result))))
--8<---------------cut here---------------end--------------->8---

Best regards, Michael.



Reply | Threaded
Open this post in threaded view
|

bug#42538: 28.0.50; tramp-test35-remote-path test timing out on macOS

Andreas Schwab-2
On Jul 31 2020, Michael Albinus wrote:

> I see. `tramp-get-signal-strings' is problematic anyway, because it runs
> locally, but shall serve the signal strings for the remote host. Maybe,
> we shall assume standardized signal strings up to 15 only.

Even then you have variation among architectures on Linux alone.  For
example, SIGBUS can be 10 or 7.

Andreas.

--
Andreas Schwab, [hidden email]
GPG Key fingerprint = 7578 EB47 D4E5 4D69 2510  2552 DF73 E780 A9DA AEC1
"And now for something completely different."



Reply | Threaded
Open this post in threaded view
|

bug#42538: 28.0.50; tramp-test35-remote-path test timing out on macOS

Philipp Stephani
In reply to this post by Michael Albinus
Am Fr., 31. Juli 2020 um 20:04 Uhr schrieb Michael Albinus
<[hidden email]>:

>
> Philipp Stephani <[hidden email]> writes:
>
> Hi Philipp,
>
> >> Thanks for the analysis. However, I fail to see where Tramp fires the
> >> command 'kill -17 $$'. There's only 'kill -2 $$'. Could you, please, show me?
> >
> > `tramp-get-signal-strings' invokes "bash -c 'kill -NUM $$'" for all
> > signal numbers, including 17. It excluded 19, assuming that's SIGSTOP,
> > but that assumption doesn't hold on macOS (or FreeBSD, or any non-x86
> > system, FWIW).
>
> I see. `tramp-get-signal-strings' is problematic anyway, because it runs
> locally, but shall serve the signal strings for the remote host. Maybe,
> we shall assume standardized signal strings up to 15 only.

Even that assumption doesn't hold, even if restricted to a single
operating system. See e.g. the per-architecture signal number table at
https://man7.org/linux/man-pages/man7/signal.7.html.
How about using the fallback ("Signal #123") in all cases? In practice
the signal descriptions aren't portable, so users can't parse them
anyway.



Reply | Threaded
Open this post in threaded view
|

bug#42538: 28.0.50; tramp-test35-remote-path test timing out on macOS

Michael Albinus
Philipp Stephani <[hidden email]> writes:

Hi Philipp,

> Even that assumption doesn't hold, even if restricted to a single
> operating system. See e.g. the per-architecture signal number table at
> https://man7.org/linux/man-pages/man7/signal.7.html.
> How about using the fallback ("Signal #123") in all cases? In practice
> the signal descriptions aren't portable, so users can't parse them
> anyway.

I've tried an alternative implementation, getting the string from the
remote host (and caching it then). Pushed to master. Could you, pls, check?

Best regards, Michael.



Reply | Threaded
Open this post in threaded view
|

bug#42538: 28.0.50; tramp-test35-remote-path test timing out on macOS

Philipp Stephani
Am Sa., 1. Aug. 2020 um 20:15 Uhr schrieb Michael Albinus
<[hidden email]>:

>
> Philipp Stephani <[hidden email]> writes:
>
> Hi Philipp,
>
> > Even that assumption doesn't hold, even if restricted to a single
> > operating system. See e.g. the per-architecture signal number table at
> > https://man7.org/linux/man-pages/man7/signal.7.html.
> > How about using the fallback ("Signal #123") in all cases? In practice
> > the signal descriptions aren't portable, so users can't parse them
> > anyway.
>
> I've tried an alternative implementation, getting the string from the
> remote host (and caching it then). Pushed to master. Could you, pls, check?

It doesn't hang for me any more, thanks. Now I only get the "normal"
test failure:

Test tramp-test33-environment-variables condition:
    (ert-test-failed
     ((should
       (string-equal
(format "%s,tramp:%s" emacs-version tramp-version)
(funcall this-shell-command-to-string "echo -n ${INSIDE_EMACS:-bla}")))
      :form
      (string-equal "28.0.50,tramp:2.5.0-pre" "-n 28.0.50,tramp:2.5.0-pre
")
      :value nil))
   FAILED  45/68  tramp-test33-environment-variables (0.198462 sec)

It looks like this "echo" command/builtin doesn't support "-n".



Reply | Threaded
Open this post in threaded view
|

bug#42538: 28.0.50; tramp-test35-remote-path test timing out on macOS

Philipp Stephani
Am Sa., 1. Aug. 2020 um 21:24 Uhr schrieb Philipp Stephani
<[hidden email]>:

>
> Am Sa., 1. Aug. 2020 um 20:15 Uhr schrieb Michael Albinus
> <[hidden email]>:
> >
> > Philipp Stephani <[hidden email]> writes:
> >
> > Hi Philipp,
> >
> > > Even that assumption doesn't hold, even if restricted to a single
> > > operating system. See e.g. the per-architecture signal number table at
> > > https://man7.org/linux/man-pages/man7/signal.7.html.
> > > How about using the fallback ("Signal #123") in all cases? In practice
> > > the signal descriptions aren't portable, so users can't parse them
> > > anyway.
> >
> > I've tried an alternative implementation, getting the string from the
> > remote host (and caching it then). Pushed to master. Could you, pls, check?
>
> It doesn't hang for me any more, thanks. Now I only get the "normal"
> test failure:
>
> Test tramp-test33-environment-variables condition:
>     (ert-test-failed
>      ((should
>        (string-equal
> (format "%s,tramp:%s" emacs-version tramp-version)
> (funcall this-shell-command-to-string "echo -n ${INSIDE_EMACS:-bla}")))
>       :form
>       (string-equal "28.0.50,tramp:2.5.0-pre" "-n 28.0.50,tramp:2.5.0-pre
> ")
>       :value nil))
>    FAILED  45/68  tramp-test33-environment-variables (0.198462 sec)
>
> It looks like this "echo" command/builtin doesn't support "-n".

And some more errors:

Test tramp-test41-utf8 condition:
    (file-error "Couldn't write region to
`/mock:p:/private/var/folders/ks/sxl3n3w51td0ry21j3tjs1wh0000gn/T/tramp-testihxoo1/Tibetan
(བོད་སྐ????ད་) ༄༅༅༎བཀྲ????་ཤིས་བདེ་ལེགས༎ཨོཾ་མ????་ཎི་པ????དྨེ་ཧའུྂ༎',
decode using `base64 -d >%s' failed")
   FAILED  59/68  tramp-test41-utf8 (26.238610 sec)

Test tramp-test41-utf8-with-ls condition:
    (file-error "Couldn't write region to
`/mock:p:/private/var/folders/ks/sxl3n3w51td0ry21j3tjs1wh0000gn/T/tramp-testjjBt88/Tibetan
(བོད་སྐ????ད་) ༄༅༅༎བཀྲ????་ཤིས་བདེ་ལེགས༎ཨོཾ་མ????་ཎི་པ????དྨེ་ཧའུྂ༎',
decode using `base64 -d >%s' failed")
   FAILED  60/68  tramp-test41-utf8-with-ls (26.334114 sec)

Test tramp-test41-utf8-with-perl condition:
    (file-error "Couldn't write region to
`/mock:p:/private/var/folders/ks/sxl3n3w51td0ry21j3tjs1wh0000gn/T/tramp-testIXjq6B/Tibetan
(བོད་སྐ????ད་) ༄༅༅༎བཀྲ????་ཤིས་བདེ་ལེགས༎ཨོཾ་མ????་ཎི་པ????དྨེ་ཧའུྂ༎',
decode using `base64 -d >%s' failed")
   FAILED  61/68  tramp-test41-utf8-with-perl (26.276314 sec)



Reply | Threaded
Open this post in threaded view
|

bug#42538: 28.0.50; tramp-test35-remote-path test timing out on macOS

Michael Albinus
In reply to this post by Philipp Stephani
Philipp Stephani <[hidden email]> writes:

Hi Philipp,

> Test tramp-test33-environment-variables condition:
>     (ert-test-failed
>      ((should
>        (string-equal
> (format "%s,tramp:%s" emacs-version tramp-version)
> (funcall this-shell-command-to-string "echo -n ${INSIDE_EMACS:-bla}")))
>       :form
>       (string-equal "28.0.50,tramp:2.5.0-pre" "-n 28.0.50,tramp:2.5.0-pre
> ")
>       :value nil))
>    FAILED  45/68  tramp-test33-environment-variables (0.198462 sec)
>
> It looks like this "echo" command/builtin doesn't support "-n".

You're right, "echo -n" isn't portable. The POSIX standard mentions it:

"It is not possible to use echo portably across all POSIX systems unless
both -n (as the first argument) and escape sequences are omitted."

I fixed it, pushed to master.

Best regards, Michael.



Reply | Threaded
Open this post in threaded view
|

bug#42538: 28.0.50; tramp-test35-remote-path test timing out on macOS

Michael Albinus
In reply to this post by Philipp Stephani
Philipp Stephani <[hidden email]> writes:

Hi Philipp,

> And some more errors:
>
> Test tramp-test41-utf8 condition:
>     (file-error "Couldn't write region to
> `/mock:p:/private/var/folders/ks/sxl3n3w51td0ry21j3tjs1wh0000gn/T/tramp-testihxoo1/Tibetan
> (བོད་སྐ????ད་) ༄༅༅༎བཀྲ????་ཤིས་བདེ་ལེགས༎ཨོཾ་མ????་ཎི་པ????དྨེ་ཧའུྂ༎',
> decode using `base64 -d >%s' failed")
>    FAILED  59/68  tramp-test41-utf8 (26.238610 sec)

Hard to debug. The "?" chars indicate, that the string isn't visible
completely in your Emacs instance (it is for me).

I've added a check in the test cases, avoiding not displayable
characters. Pushed to master.

Best regards, Michael.
12