bug#73046: 29.4; Emacs 100% CPU usage for several seconds when opening dired buffer over TRAMP

bug#73046: 29.4; Emacs 100% CPU usage for several seconds when opening dired buffer over TRAMP

[Suhail Singh]

I observe 100% CPU usage for several seconds when invoking dired for a
directory on one of the remote machines I connect to.  This doesn't seem
to happen for another host.  The connection to the affected host is
slower, and on that host the issue is worse when the directory has
several symlinks.

To reproduce via =emacs -Q=:
- Invoke `find-file' and connect to problematic host over ssh.
- Once connection is established, open dired pointing to a directory on
  the affected host.
- Observe bug: it takes _several_ seconds for the dired buffer to show.
  During that time, Emacs CPU usage is 100%.
- Once dired buffer is open, invoke `revert-buffer' and observe issue
  again.

Disabling global-font-lock-mode, makes the situation better.

Given that rudimentary font-locking should be possible via, simply, the
output of `ls --dired', it is unclear why enabling font-locking makes
things so much worse.  If there are some aspects of font-locking that
perform much worse over a slower connection, it would help if there were
a user configuration to disable them.

It would also help if being over a slow connection didn't result in
Emacs consuming 100% of the CPU via functions such as
`tramp-wait-for-regexp' (based on profiler-report).  Could some of this
be done asynchronously?


In GNU Emacs 29.4 (build 2, x86_64-suse-linux-gnu, GTK+ Version 3.24.43,
cairo version 1.18.0)
System Description: openSUSE Tumbleweed

Configured using:
 'configure --disable-build-details --without-pop --with-mailutils
 --with-native-compilation --without-hesiod --with-gameuser=:games
 --with-kerberos --with-kerberos5 --with-file-notification=inotify
 --with-modules --enable-autodepend --prefix=/usr
 --mandir=/usr/share/man --infodir=/usr/share/info --datadir=/usr/share
 --localstatedir=/var --sharedstatedir=/var/lib
 --libexecdir=/usr/libexec --with-file-notification=yes
 --libdir=/usr/lib64
 --enable-locallisppath=/usr/share/emacs/29.4/site-lisp:/usr/share/emacs/site-lisp
 --with-x --with-xim --with-sound --with-xpm --with-jpeg --with-tiff
 --with-gif --with-png --with-rsvg --with-dbus --with-webp --with-xft
 --with-imagemagick --without-gpm --with-x-toolkit=gtk3 --with-pgtk
 --with-toolkit-scroll-bars --x-includes=/usr/include
 --x-libraries=/usr/lib64 --with-libotf --with-m17n-flt --with-cairo
 --with-xwidgets --build=x86_64-suse-linux --with-dumping=pdumper
 'CFLAGS=-O2 -Wall -U_FORTIFY_SOURCE -D_FORTIFY_SOURCE=3
 -fstack-protector-strong -funwind-tables -fasynchronous-unwind-tables
 -fstack-clash-protection -Werror=return-type -flto=auto -g
 -D_GNU_SOURCE -DGDK_DISABLE_DEPRECATION_WARNINGS
 -DGLIB_DISABLE_DEPRECATION_WARNINGS -pipe -Wno-pointer-sign
 -Wno-unused-variable -Wno-unused-label -fno-optimize-sibling-calls
 -DPDMP_BASE='\''"emacs-wayland"'\''' LDFLAGS=-Wl,-O2'

Configured features:
ACL CAIRO DBUS FREETYPE GIF GLIB GMP GNUTLS GSETTINGS HARFBUZZ
IMAGEMAGICK JPEG JSON LCMS2 LIBOTF LIBSELINUX LIBSYSTEMD LIBXML2 MODULES
NATIVE_COMP NOTIFY INOTIFY PDUMPER PGTK PNG RSVG SECCOMP SOUND SQLITE3
THREADS TIFF TOOLKIT_SCROLL_BARS TREE_SITTER WEBP XIM XWIDGETS GTK3 ZLIB

Important settings:
  value of $LC_NUMERIC: POSIX
  value of $LC_TIME: en_US.UTF-8
  value of $LANG: en_US.UTF-8
  locale-coding-system: utf-8-unix

Major mode: Dired by name

Minor modes in effect:
  shell-dirtrack-mode: t
  tooltip-mode: t
  global-eldoc-mode: t
  show-paren-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
  buffer-read-only: t
  line-number-mode: t
  indent-tabs-mode: t
  transient-mark-mode: t
  auto-composition-mode: t
  auto-encryption-mode: t
  auto-compression-mode: t

Load-path shadows:
None found.

Features:
(shadow sort mail-extr emacsbug message mailcap yank-media puny rfc822
mml mml-sec epa derived epg rfc6068 epg-config gnus-util
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 dired-aux dired dired-loaddefs tramp-sh
tramp-cache time-stamp tramp tramp-loaddefs trampver tramp-integration
files-x tramp-compat rx shell pcomplete comint ansi-osc ring parse-time
iso8601 time-date format-spec auth-source cl-seq eieio eieio-core
cl-macs cl-loaddefs cl-lib password-cache json subr-x map byte-opt gv
bytecomp byte-compile ansi-color rmc delsel lpr easy-mmode pcase
iso-transl tooltip cconv eldoc paren electric uniquify ediff-hook
vc-hooks lisp-float-type elisp-mode mwheel term/pgtk-win pgtk-win
term/common-win pgtk-dnd tool-bar dnd fontset image regexp-opt fringe
tabulated-list replace newcomment text-mode lisp-mode prog-mode register
page tab-bar menu-bar rfn-eshadow isearch easymenu timer select
scroll-bar mouse jit-lock font-lock syntax font-core term/tty-colors
frame minibuffer nadvice seq simple cl-generic indonesian philippine
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 emoji-zwj charscript
charprop case-table epa-hook jka-cmpr-hook help abbrev obarray oclosure
cl-preloaded button loaddefs theme-loaddefs faces cus-face macroexp
files window text-properties overlay sha1 md5 base64 format env
code-pages mule custom widget keymap hashtable-print-readable backquote
threads xwidget-internal dbusbind inotify dynamic-setting
system-font-setting font-render-setting cairo gtk pgtk lcms2 multi-tty
make-network-process native-compile emacs)

Memory information:
((conses 16 94415 10209)
 (symbols 48 8472 0)
 (strings 32 27423 1593)
 (string-bytes 1 934096)
 (vectors 16 17482)
 (vector-slots 8 388602 12097)
 (floats 8 33 35)
 (intervals 56 549 0)
 (buffers 984 12))

-- 
Suhail

bug#73046: 29.4; Emacs 100% CPU usage for several seconds when opening dired buffer over TRAMP

[Eli Zaretskii]

> From: "Suhail Singh" <suhailsingh247@gmail.com>
> Date: Thu, 05 Sep 2024 10:24:54 -0400
> 
> 
> I observe 100% CPU usage for several seconds when invoking dired for a
> directory on one of the remote machines I connect to.  This doesn't seem
> to happen for another host.  The connection to the affected host is
> slower, and on that host the issue is worse when the directory has
> several symlinks.
> 
> To reproduce via =emacs -Q=:
> - Invoke `find-file' and connect to problematic host over ssh.
> - Once connection is established, open dired pointing to a directory on
>   the affected host.
> - Observe bug: it takes _several_ seconds for the dired buffer to show.
>   During that time, Emacs CPU usage is 100%.
> - Once dired buffer is open, invoke `revert-buffer' and observe issue
>   again.
> 
> Disabling global-font-lock-mode, makes the situation better.
> 
> Given that rudimentary font-locking should be possible via, simply, the
> output of `ls --dired', it is unclear why enabling font-locking makes
> things so much worse.  If there are some aspects of font-locking that
> perform much worse over a slower connection, it would help if there were
> a user configuration to disable them.
> 
> It would also help if being over a slow connection didn't result in
> Emacs consuming 100% of the CPU via functions such as
> `tramp-wait-for-regexp' (based on profiler-report).  Could some of this
> be done asynchronously?

You could probably tell which parts take the time by profiling Emacs
while it collects the Dired data, using profiler.el.  This could give
clues about the expensive parts.  My guess would be that retrieving
the attributes of the files Dired needs are the reason, but I could be
wrong.

bug#73046: 29.4; Emacs 100% CPU usage for several seconds when opening dired buffer over TRAMP

[Suhail Singh]

Eli Zaretskii <eliz@gnu.org> writes:

>> From: "Suhail Singh" <suhailsingh247@gmail.com>
>> Date: Thu, 05 Sep 2024 10:24:54 -0400
>> 
>> 
>> I observe 100% CPU usage for several seconds when invoking dired for a
>> directory on one of the remote machines I connect to.  This doesn't seem
>> to happen for another host.  The connection to the affected host is
>> slower, and on that host the issue is worse when the directory has
>> several symlinks.
>> 
>> To reproduce via =emacs -Q=:
>> - Invoke `find-file' and connect to problematic host over ssh.
>> - Once connection is established, open dired pointing to a directory on
>>   the affected host.
>> - Observe bug: it takes _several_ seconds for the dired buffer to show.
>>   During that time, Emacs CPU usage is 100%.
>> - Once dired buffer is open, invoke `revert-buffer' and observe issue
>>   again.
>> 
>> Disabling global-font-lock-mode, makes the situation better.
>> 
>> Given that rudimentary font-locking should be possible via, simply, the
>> output of `ls --dired', it is unclear why enabling font-locking makes
>> things so much worse.  If there are some aspects of font-locking that
>> perform much worse over a slower connection, it would help if there were
>> a user configuration to disable them.
>> 
>> It would also help if being over a slow connection didn't result in
>> Emacs consuming 100% of the CPU via functions such as
>> `tramp-wait-for-regexp' (based on profiler-report).  Could some of this
>> be done asynchronously?
>
> You could probably tell which parts take the time by profiling Emacs
> while it collects the Dired data, using profiler.el.  This could give
> clues about the expensive parts.  My guess would be that retrieving
> the attributes of the files Dired needs are the reason, but I could be
> wrong.

Based on =profiler-report=, the following function "chains" consume most of the
CPU:
- `font-lock-fontify-keywords-region'
  - tramp-sh-file-name-handler
    - tramp-sh-handle-file-truename
      - `tramp-wait-for-regexp'
    - tramp-sh-handle-file-exists-p
      - `tramp-wait-for-regexp'
    - tramp-sh-handle-file-directory-p
      - `tramp-wait-for-regexp'
    - tramp-sh-handle-file-attributes
      - `tramp-wait-for-regexp'

As noted previously, disabling global-font-lock-mode helps.

In related news, one thing I've observed on the affected host is that
the version of `ls' doesn't seem to yield expected output for
`ls --dired'.  Specifically, the output of `ls --dired' is the same as
the output of `ls' (i.e., `--dired' gets treated as a no-op).  The version
of `ls' on this host is:

#+begin_quote
  ls (GNU coreutils) 8.32
  Copyright (C) 2020 Free Software Foundation, Inc.
  License GPLv3+: GNU GPL version 3 or later <https://gnu.org/licenses/gpl.html>.
  This is free software: you are free to change and redistribute it.
  There is NO WARRANTY, to the extent permitted by law.

  Written by Richard M. Stallman and David MacKenzie.
#+end_quote

-- 
Suhail

bug#73046: 29.4; Emacs 100% CPU usage for several seconds when opening dired buffer over TRAMP

[Eli Zaretskii]

> From: Suhail Singh <suhailsingh247@gmail.com>
> Cc: "Suhail Singh" <suhailsingh247@gmail.com>,  73046@debbugs.gnu.org
> Date: Thu, 05 Sep 2024 17:04:23 -0400
> 
> Eli Zaretskii <eliz@gnu.org> writes:
> 
> >> It would also help if being over a slow connection didn't result in
> >> Emacs consuming 100% of the CPU via functions such as
> >> `tramp-wait-for-regexp' (based on profiler-report).  Could some of this
> >> be done asynchronously?
> >
> > You could probably tell which parts take the time by profiling Emacs
> > while it collects the Dired data, using profiler.el.  This could give
> > clues about the expensive parts.  My guess would be that retrieving
> > the attributes of the files Dired needs are the reason, but I could be
> > wrong.
> 
> Based on =profiler-report=, the following function "chains" consume most of the
> CPU:
> - `font-lock-fontify-keywords-region'
>   - tramp-sh-file-name-handler
>     - tramp-sh-handle-file-truename
>       - `tramp-wait-for-regexp'
>     - tramp-sh-handle-file-exists-p
>       - `tramp-wait-for-regexp'
>     - tramp-sh-handle-file-directory-p
>       - `tramp-wait-for-regexp'
>     - tramp-sh-handle-file-attributes
>       - `tramp-wait-for-regexp'
> 
> As noted previously, disabling global-font-lock-mode helps.

FWIW, I cannot reproduce this: I tried Dired on a remote host with
which I have connection that is quite slow, and saw neither high CPU
usage nor a significant delay in displaying a Dired buffer.

> In related news, one thing I've observed on the affected host is that
> the version of `ls' doesn't seem to yield expected output for
> `ls --dired'.  Specifically, the output of `ls --dired' is the same as
> the output of `ls' (i.e., `--dired' gets treated as a no-op).

This could indeed explain the problem.  However, ...

> The version of `ls' on this host is:
> 
> #+begin_quote
>   ls (GNU coreutils) 8.32
>   Copyright (C) 2020 Free Software Foundation, Inc.
>   License GPLv3+: GNU GPL version 3 or later <https://gnu.org/licenses/gpl.html>.
>   This is free software: you are free to change and redistribute it.
>   There is NO WARRANTY, to the extent permitted by law.
> 
>   Written by Richard M. Stallman and David MacKenzie.
> #+end_quote

This cannot be true: the --dired option was added to 'ls' way earlier.
I have Coreutils 6.9 from 2007 on one of my systems, and --dired is
supported there.  To see if it is supported, try this:

  $ ls -al --dired

You should see 2 extra lines of output after the listing, each one
starting with "//DIRED".

bug#73046: 29.4; Emacs 100% CPU usage for several seconds when opening dired buffer over TRAMP

[Michael Albinus via Bug reports for GNU Emacs, the Swiss army knife of text editors]

Eli Zaretskii <eliz@gnu.org> writes:

Hi,

>> >> It would also help if being over a slow connection didn't result in
>> >> Emacs consuming 100% of the CPU via functions such as
>> >> `tramp-wait-for-regexp' (based on profiler-report).  Could some of this
>> >> be done asynchronously?
>> >
>> > You could probably tell which parts take the time by profiling Emacs
>> > while it collects the Dired data, using profiler.el.  This could give
>> > clues about the expensive parts.  My guess would be that retrieving
>> > the attributes of the files Dired needs are the reason, but I could be
>> > wrong.
>>
>> Based on =profiler-report=, the following function "chains" consume most of the
>> CPU:
>> - `font-lock-fontify-keywords-region'
>>   - tramp-sh-file-name-handler
>>     - tramp-sh-handle-file-truename
>>       - `tramp-wait-for-regexp'
>>     - tramp-sh-handle-file-exists-p
>>       - `tramp-wait-for-regexp'
>>     - tramp-sh-handle-file-directory-p
>>       - `tramp-wait-for-regexp'
>>     - tramp-sh-handle-file-attributes
>>       - `tramp-wait-for-regexp'
>>
>> As noted previously, disabling global-font-lock-mode helps.
>
> FWIW, I cannot reproduce this: I tried Dired on a remote host with
> which I have connection that is quite slow, and saw neither high CPU
> usage nor a significant delay in displaying a Dired buffer.

It seems to be related to font-locking, indeed. See variable
`dired-font-lock-keywords'. It specifies face recognition running basic
file oprtations. For example, ";; Broken Symbolic link" calls
`file-truename' and `file-exists-p', while "Symbolic link to a directory"
and ";; Symbolic link to a non-directory" invoke `file-truename' and
`file-directory-p'.

I believe it would be helpful to suppress these checks via a user
option. And no, the checks shouldn't be suppressed for remote
directories in general, on a fast connection they are valuable.

In bug#17064, the impact of these calls where discussed. The conclusion was

--8<---------------cut here---------------start------------->8---
> Or could this have any bad side effects?  Is it maybe too heavy to call
> `file-truename'?

Normally, there aren't many symlinks in a buffer, so I think the
performance impact would be negligible.
--8<---------------cut here---------------end--------------->8---

Likely, this was too optimistic ...

Best regards, Michael.

bug#73046: 29.4; Emacs 100% CPU usage for several seconds when opening dired buffer over TRAMP

[Eli Zaretskii]

> From: Michael Albinus <michael.albinus@gmx.de>
> Cc: Suhail Singh <suhailsingh247@gmail.com>,  73046@debbugs.gnu.org
> Date: Fri, 06 Sep 2024 15:23:57 +0200
> 
> > FWIW, I cannot reproduce this: I tried Dired on a remote host with
> > which I have connection that is quite slow, and saw neither high CPU
> > usage nor a significant delay in displaying a Dired buffer.
> 
> It seems to be related to font-locking, indeed. See variable
> `dired-font-lock-keywords'. It specifies face recognition running basic
> file oprtations. For example, ";; Broken Symbolic link" calls
> `file-truename' and `file-exists-p', while "Symbolic link to a directory"
> and ";; Symbolic link to a non-directory" invoke `file-truename' and
> `file-directory-p'.

But font-lock is ON by default, so what I saw also includes this,
right?

> I believe it would be helpful to suppress these checks via a user
> option.

What's wrong with "M-x font-lock-mode RET"?

bug#73046: 29.4; Emacs 100% CPU usage for several seconds when opening dired buffer over TRAMP

[Michael Albinus via Bug reports for GNU Emacs, the Swiss army knife of text editors]

Eli Zaretskii <eliz@gnu.org> writes:

Hi Eli,

>> > FWIW, I cannot reproduce this: I tried Dired on a remote host with
>> > which I have connection that is quite slow, and saw neither high CPU
>> > usage nor a significant delay in displaying a Dired buffer.
>>
>> It seems to be related to font-locking, indeed. See variable
>> `dired-font-lock-keywords'. It specifies face recognition running basic
>> file oprtations. For example, ";; Broken Symbolic link" calls
>> `file-truename' and `file-exists-p', while "Symbolic link to a directory"
>> and ";; Symbolic link to a non-directory" invoke `file-truename' and
>> `file-directory-p'.
>
> But font-lock is ON by default, so what I saw also includes this,
> right?

Sure. But we don't know the exact setting of the OP. The connection
could be extremely slow for him, Tramp's cache might be disabled,
whatever. Perhaps it's worth to rerun the test with "emacs -Q".

>> I believe it would be helpful to suppress these checks via a user
>> option.
>
> What's wrong with "M-x font-lock-mode RET"?

You would deactivate all fontifications, not only the ones related to
symlinks.

And you must do this in a hook of the dired buffer, before fontification
happens.

There exist `dired-hide-details-mode', which I don't know. Perhaps
enabling it in time would do the job?

Best regards, Michael.

bug#73046: 29.4; Emacs 100% CPU usage for several seconds when opening dired buffer over TRAMP

[Eli Zaretskii]

> From: Michael Albinus <michael.albinus@gmx.de>
> Cc: suhailsingh247@gmail.com,  73046@debbugs.gnu.org
> Date: Fri, 06 Sep 2024 16:09:23 +0200
> 
> Eli Zaretskii <eliz@gnu.org> writes:
> 
> >> It seems to be related to font-locking, indeed. See variable
> >> `dired-font-lock-keywords'. It specifies face recognition running basic
> >> file oprtations. For example, ";; Broken Symbolic link" calls
> >> `file-truename' and `file-exists-p', while "Symbolic link to a directory"
> >> and ";; Symbolic link to a non-directory" invoke `file-truename' and
> >> `file-directory-p'.
> >
> > But font-lock is ON by default, so what I saw also includes this,
> > right?
> 
> Sure. But we don't know the exact setting of the OP. The connection
> could be extremely slow for him, Tramp's cache might be disabled,
> whatever. Perhaps it's worth to rerun the test with "emacs -Q".

I think we should also try to establish how slow is that connection.
How much time does "ping" take?  How long does it take to fetch a file
of, say 20 KBytes?

Also, if font-lock is disabled, does the problem go away?

bug#73046: 29.4; Emacs 100% CPU usage for several seconds when opening dired buffer over TRAMP

[Suhail Singh]

Eli Zaretskii <eliz@gnu.org> writes:

> I think we should also try to establish how slow is that connection.
> How much time does "ping" take?

The server doesn't respond to "ping" requests so I cannot test that.
There are however more than 14 hops as reported by mtr.  How much more I
cannot say, unfortunately.

> How long does it take to fetch a file of, say 20 KBytes?

Given a 20kb file generated via:
#+begin_src sh :results verbatim
  mkdir -p /tmp/test
  cd /tmp/test
  dd if=/dev/urandom of=upload_test bs=10k count=2
  du -sh /tmp/test/upload_test
#+end_src

#+RESULTS:
: 20K	/tmp/test/upload_test

It takes ~4-6s to upload:
#+begin_src sh :results verbatim
  cd /tmp/test
  {
      time scp upload_test scp://${affected-host}//tmp/upload_test
  } 2>&1
#+end_src

#+RESULTS:
: 
: real	0m4.255s
: user	0m0.008s
: sys	0m0.002s

And a similar time to download:
#+begin_src sh :results verbatim
  cd /tmp/test
  {
      time scp scp://${affected-host}//tmp/upload_test ./download_test
  } 2>&1
#+end_src

#+RESULTS:
: 
: real	0m5.638s
: user	0m0.007s
: sys	0m0.000s


> Also, if font-lock is disabled, does the problem go away?

As noted in the original message:

>>> Disabling global-font-lock-mode, makes the situation better.

Things are still sluggish after disabling font-lock, but they are *much*
better (i.e., instead of a ~10s delay for revert-buffer we are down to
less than a second).  The remaining sluggishness seems reasonable given
what I know about the connection speed, but I have not done extensive
quantitative testing.  As such, while I cannot say with certainty if
"the problem" goes away entirely, or only mostly, it does improve
significantly.

-- 
Suhail

bug#73046: 29.4; Emacs 100% CPU usage for several seconds when opening dired buffer over TRAMP

[Eli Zaretskii]

> From: Suhail Singh <suhailsingh247@gmail.com>
> Cc: suhailsingh247@gmail.com,  Michael Albinus <michael.albinus@gmx.de>,
>   73046@debbugs.gnu.org
> Date: Fri, 06 Sep 2024 13:47:54 -0400
> 
> > How long does it take to fetch a file of, say 20 KBytes?
> 
> Given a 20kb file generated via:
> #+begin_src sh :results verbatim
>   mkdir -p /tmp/test
>   cd /tmp/test
>   dd if=/dev/urandom of=upload_test bs=10k count=2
>   du -sh /tmp/test/upload_test
> #+end_src
> 
> #+RESULTS:
> : 20K	/tmp/test/upload_test
> 
> It takes ~4-6s to upload:
> #+begin_src sh :results verbatim
>   cd /tmp/test
>   {
>       time scp upload_test scp://${affected-host}//tmp/upload_test
>   } 2>&1
> #+end_src
> 
> #+RESULTS:
> : 
> : real	0m4.255s
> : user	0m0.008s
> : sys	0m0.002s
> 
> And a similar time to download:
> #+begin_src sh :results verbatim
>   cd /tmp/test
>   {
>       time scp scp://${affected-host}//tmp/upload_test ./download_test
>   } 2>&1
> #+end_src
> 
> #+RESULTS:
> : 
> : real	0m5.638s
> : user	0m0.007s
> : sys	0m0.000s
> 
> 
> > Also, if font-lock is disabled, does the problem go away?
> 
> As noted in the original message:
> 
> >>> Disabling global-font-lock-mode, makes the situation better.
> 
> Things are still sluggish after disabling font-lock, but they are *much*
> better (i.e., instead of a ~10s delay for revert-buffer we are down to
> less than a second).  The remaining sluggishness seems reasonable given
> what I know about the connection speed, but I have not done extensive
> quantitative testing.  As such, while I cannot say with certainty if
> "the problem" goes away entirely, or only mostly, it does improve
> significantly.

So if it takes 4 to 5 sec to move a 20KB file, then how much stuff
needs to be moved for the Dired listing?  What does the below show, if
you run it on that remote machine?

  $ ls -al | wc

It needs to show around 40KB to explain 10 sec of delay.

bug#73046: 29.4; Emacs 100% CPU usage for several seconds when opening dired buffer over TRAMP

[Suhail Singh]

Eli Zaretskii <eliz@gnu.org> writes:

> So if it takes 4 to 5 sec to move a 20KB file, then how much stuff
> needs to be moved for the Dired listing?  What does the below show, if
> you run it on that remote machine?
>
>   $ ls -al | wc

Given that the contents of the remote directory can be exactly
replicated (apart from metadata such as mtime etc) by the below code
(that I shared in another response), you should be able to answer the
question trivially:

#+name: perf-fix/tramp/font-lock-on-dired/reproducer
#+begin_src sh
  cd /tmp
  rm -rf /tmp/test
  mkdir /tmp/test
  cd /tmp/test
  for i in `seq -w 0 21`; do
      mkdir -p src/"$i"
  done
  mkdir -p links
  cd links
  for i in `seq -w 0 21`; do
      ln -sf /tmp/test/src/"$i"
  done
#+end_src

For the record, the output is as follows:

#+begin_src sh :dir /ssh:${affected-host}:/tmp
  cd /tmp/test/links
  ls -al | wc
#+end_src

#+RESULTS:
: 25     262    1599


> It needs to show around 40KB to explain 10 sec of delay.

I don't understand your reasoning.  In fact if the output of ls -al was
indeed around 40kb I would have been very surprised.  The time taken for
transferring the 20KB file included initial connection costs whereas
TRAMP would presumably be reusing the same connection, but would be
sending multiple small requests.  I don't see how one can be compared to
the other, other than to say (generally) that when connection is slow
both workflows would take greater time (which is what we observe).

Note that disabling font-lock improved response delay considerably.
That means the delay is not due to transferring information contained in
`ls --dired', which is considerably fast (relatively speaking), but in
doing the additional checks that Michael mentioned:

>>> It seems to be related to font-locking, indeed. See variable
>>> `dired-font-lock-keywords'. It specifies face recognition running basic
>>> file oprtations. For example, ";; Broken Symbolic link" calls
>>> `file-truename' and `file-exists-p', while "Symbolic link to a directory"
>>> and ";; Symbolic link to a non-directory" invoke `file-truename' and
>>> `file-directory-p'.

I did some further investigation; summarizing findings below:

A. On Host-A, the network connection is fairly slow s.t. transferring a
   20KB file takes ~5s.  On Host-B, the network connection is fairly
   fast.

B. On Host-A, the time taken to refresh dired buffer containing 22
   Subdirectories (/tmp/test/src as in above code snippet) is 0.70-0.75s
   with font-lock enabled, and about the same with font-lock disabled.
   These times exclude the time taken to establish the intiial
   connection over TRAMP.

C. On Host-A, the time taken to refresh dired buffer containing 22
   symlinks (each symlink pointing to a directory, i.e., /tmp/test/links
   in the above code snippet) is 0.70-0.75s with font-lock disabled.
   With font-lock enabled the time taken is ~13-14s and the CPU is at
   100%.  These times exclude the time taken to establish the intiial
   connection over TRAMP.

D. On Host-B, the time taken to display dired buffer for /tmp/test/links
   with font-lock enabled is ~2s greater than when font-lock is
   disabled.  When /tmp/test/links contains 100 symlinks to directories
   (instead of 22), the time taken when font-lock is enabled is ~6s
   greater than when font-lock is disabled.

Given above, I conclude:

1. The issue is present when there are symlinks to directories.

2. The issue is worse when there are greater number of symlinks to
   directories.

2. The issue is worse when the connection is slower.  However, it is
   still observable when the connection is faster - if you're having
   difficulty reproducing, increase the number of symlinks to
   directories in /tmp/test/links above.

3. Given that when connection is slower, not only is the time taken for
   font-locking greater, but the CPU is at 100%, I suspect that the
   relevant code is doing some kind of busy-waiting.

The above observations seem consistent with Michael's comments above
regd. font-lock checks for "Broken Symbolink link" and "Symbolic link to
a directory".  As such, if Michael's proposal below is implemented I
believe it would be an adequate fix to the issue:

>>> I believe it would be helpful to suppress these checks via a user
>>> option. And no, the checks shouldn't be suppressed for remote
>>> directories in general, on a fast connection they are valuable.

I hope that clarifies things, and gives you sufficient information to be
able to reproduce

-- 
Suhail

bug#73046: 29.4; Emacs 100% CPU usage for several seconds when opening dired buffer over TRAMP

[Suhail Singh]

Suhail Singh <suhailsingh247@gmail.com> writes:

>>>> It seems to be related to font-locking, indeed. See variable
>>>> `dired-font-lock-keywords'. It specifies face recognition running basic
>>>> file oprtations. For example, ";; Broken Symbolic link" calls
>>>> `file-truename' and `file-exists-p', while "Symbolic link to a directory"
>>>> and ";; Symbolic link to a non-directory" invoke `file-truename' and
>>>> `file-directory-p'.
> ...
>>>> I believe it would be helpful to suppress these checks via a user
>>>> option.

For the benefit of others, absent such a user option, the below code
works around the issue:

#+begin_src emacs-lisp
  (add-hook 'dired-mode-hook
  	  (lambda ()
  	    (setq-local dired-font-lock-keywords
  			(cons
  			 (list dired-re-sym
  			       '(".+" (dired-move-to-filename) nil (0 dired-symlink-face)))
  			 (seq-remove (lambda (x)
  				       (string= (car x) dired-re-sym))
  				     dired-font-lock-keywords)))))
#+end_src

I believe that the above isn't a fix, but simply a workaround since
TRAMP awaiting a response over a slow connection shouldn't result in
100% CPU usage.  Functions such as `tramp-wait-for-regexp' should not be
using excess CPU when they are simply awaiting a response.

>>>> And no, the checks shouldn't be suppressed for remote directories
>>>> in general, on a fast connection they are valuable.

For this reason, those interested in working around the issue in a
similar manner as above, may want to add additional guards to the hook
to ensure that the informative font-locking is suppressed (by modifying
dired-font-lock-keywords) only when necessary.

-- 
Suhail

bug#73046: 29.4; Emacs 100% CPU usage for several seconds when opening dired buffer over TRAMP

[Eli Zaretskii]

> From: Suhail Singh <suhailsingh247@gmail.com>
> Cc: Suhail Singh <suhailsingh247@gmail.com>,  michael.albinus@gmx.de,
>   73046@debbugs.gnu.org
> Date: Fri, 06 Sep 2024 20:19:34 -0400
> 
> Eli Zaretskii <eliz@gnu.org> writes:
> 
> > It needs to show around 40KB to explain 10 sec of delay.
> 
> I don't understand your reasoning.

It's simple arithmetics: if fetching a 20KB file takes 4 to 5 sec,
then the 10-sec delay you reported for Dired should mean we are
fetching about 40KB of data.

> In fact if the output of ls -al was indeed around 40kb I would have
> been very surprised.

In my home directory I get:

 $ ls -al ~ | wc
     708    6371   43324

So a large enough (but not outlandishly large: just 700 files)
directory can indeed mean Emacs needs to fetch 40KB of data for
refreshing a Dired buffer.  Which led me to believe this is not an
impossible situation.

> The time taken for transferring the 20KB file included initial
> connection costs whereas TRAMP would presumably be reusing the same
> connection, but would be sending multiple small requests.

This just makes my argument stronger: it would mean that even 40KB
data moved for Dired would not quite explain the 10-sec delay.

> I did some further investigation; summarizing findings below:
> 
> A. On Host-A, the network connection is fairly slow s.t. transferring a
>    20KB file takes ~5s.  On Host-B, the network connection is fairly
>    fast.
> 
> B. On Host-A, the time taken to refresh dired buffer containing 22
>    Subdirectories (/tmp/test/src as in above code snippet) is 0.70-0.75s
>    with font-lock enabled, and about the same with font-lock disabled.
>    These times exclude the time taken to establish the intiial
>    connection over TRAMP.
> 
> C. On Host-A, the time taken to refresh dired buffer containing 22
>    symlinks (each symlink pointing to a directory, i.e., /tmp/test/links
>    in the above code snippet) is 0.70-0.75s with font-lock disabled.
>    With font-lock enabled the time taken is ~13-14s and the CPU is at
>    100%.  These times exclude the time taken to establish the intiial
>    connection over TRAMP.
> 
> D. On Host-B, the time taken to display dired buffer for /tmp/test/links
>    with font-lock enabled is ~2s greater than when font-lock is
>    disabled.  When /tmp/test/links contains 100 symlinks to directories
>    (instead of 22), the time taken when font-lock is enabled is ~6s
>    greater than when font-lock is disabled.
> 
> Given above, I conclude:
> 
> 1. The issue is present when there are symlinks to directories.
> 
> 2. The issue is worse when there are greater number of symlinks to
>    directories.
> 
> 2. The issue is worse when the connection is slower.  However, it is
>    still observable when the connection is faster - if you're having
>    difficulty reproducing, increase the number of symlinks to
>    directories in /tmp/test/links above.
> 
> 3. Given that when connection is slower, not only is the time taken for
>    font-locking greater, but the CPU is at 100%, I suspect that the
>    relevant code is doing some kind of busy-waiting.

Thanks you.  So the problem seems to be symlinks, and specifically
symlinks to directories.  Michael, what does Tramp do specially in
these cases that could explain the slowdown?

> The above observations seem consistent with Michael's comments above
> regd. font-lock checks for "Broken Symbolink link" and "Symbolic link to
> a directory".

Michael, what do these checks entail, and why are they so
CPU-expensive and take a lot of time with slow connections?

bug#73046: 29.4; Emacs 100% CPU usage for several seconds when opening dired buffer over TRAMP

[Suhail Singh]

Eli Zaretskii <eliz@gnu.org> writes:

> Thanks you.  So the problem seems to be symlinks, and specifically
> symlinks to directories.

After sending the penultimate email, and before sending the last (which
contained the workaround for modifying `dired-font-lock-keywords'
buffer-locally) I ran some more tests, and symbolic links to files are
also problematic.

Specifically, it's the three checks marked by the following comments in
`dired-font-lock-keywords' that are problematic:

- ";; Broken Symbolic link."
- ";; Symbolic link to a directory."
- ";; Symbolic link to a non-directory."

Only when the three entries corresponding to the above are removed from
`dired-font-lock-keywords', does the issue get resolved.  Removing some
(but not all) of the entries improves matters, but doesn't resolve them
completely.  Quoting Michael:

#+begin_quote
  It seems to be related to font-locking, indeed. See variable
  `dired-font-lock-keywords'. It specifies face recognition running basic
  file oprtations. For example, ";; Broken Symbolic link" calls
  `file-truename' and `file-exists-p', while "Symbolic link to a directory"
  and ";; Symbolic link to a non-directory" invoke `file-truename' and
  `file-directory-p'.

  I believe it would be helpful to suppress these checks via a user
  option. And no, the checks shouldn't be suppressed for remote
  directories in general, on a fast connection they are valuable.
#+end_quote

> Michael, what does Tramp do specially in these cases that could
> explain the slowdown?
>
>> The above observations seem consistent with Michael's comments above
>> regd. font-lock checks for "Broken Symbolink link" and "Symbolic link to
>> a directory".
>
> Michael, what do these checks entail, and why are they so
> CPU-expensive and take a lot of time with slow connections?

-- 
Suhail

bug#73046: 29.4; Emacs 100% CPU usage for several seconds when opening dired buffer over TRAMP

[Michael Albinus via Bug reports for GNU Emacs, the Swiss army knife of text editors]

Eli Zaretskii <eliz@gnu.org> writes:

Hi Eli,

> Thanks you.  So the problem seems to be symlinks, and specifically
> symlinks to directories.  Michael, what does Tramp do specially in
> these cases that could explain the slowdown?
>
>> The above observations seem consistent with Michael's comments above
>> regd. font-lock checks for "Broken Symbolink link" and "Symbolic link to
>> a directory".
>
> Michael, what do these checks entail, and why are they so
> CPU-expensive and take a lot of time with slow connections?

I made a test. In a remote directory I have created a cyclic symlink
"zzz", in order to see what Tramp does when running dired on the
directory. The additional actions are

--8<---------------cut here---------------start------------->8---
16:26:26.596764 tramp-send-command (6) # test -d /home/albinus/tmp/zzz 2>/dev/null; echo tramp_exit_status $?
16:26:26.598277 tramp-wait-for-regexp (6) # 
tramp_exit_status 1
///dd77c20acbfe3e98bd0661ddf70b1f4a#$
16:26:26.601447 tramp-send-command (6) # (if test -h "/home/albinus/tmp/zzz"; then echo t; else echo nil; fi) && \readlink --canonicalize-missing /home/albinus/tmp/zzz 2>/dev/null; echo tramp_exit_status $?
16:26:26.620202 tramp-wait-for-regexp (6) # 
t
/home/albinus/tmp/zzz
tramp_exit_status 0
///dd77c20acbfe3e98bd0661ddf70b1f4a#$
16:26:26.621815 tramp-send-command (6) # tramp_stat_file_attributes_with_selinux /home/albinus/tmp/zzz 2>/dev/null; echo tramp_exit_status $?
16:26:26.701825 tramp-wait-for-regexp (6) # 
(("‘/home/albinus/tmp/zzz’ -> ‘/home/albinus/tmp/zzz’") 1 ("albinus" . 1000) ("albinus" . 1000) 1725715198 1725627151 1725627151 21 "lrwxrwxrwx" t 11020655 -1 "unconfined_u:object_r:user_tmp_t:s0")
tramp_exit_status 0
///dd77c20acbfe3e98bd0661ddf70b1f4a#$
16:26:26.727631 tramp-send-command (6) # (if test -h "/home/albinus/tmp/zzz"; then echo t; else echo nil; fi) && \readlink --canonicalize-missing /home/albinus/tmp/zzz 2>/dev/null; echo tramp_exit_status $?
16:26:26.744351 tramp-wait-for-regexp (6) # 
t
/home/albinus/tmp/zzz
tramp_exit_status 0
///dd77c20acbfe3e98bd0661ddf70b1f4a#$
16:26:26.763045 tramp-send-command (6) # (if test -h "/home/albinus/tmp/zzz"; then echo t; else echo nil; fi) && \readlink --canonicalize-missing /home/albinus/tmp/zzz 2>/dev/null; echo tramp_exit_status $?
16:26:26.844666 tramp-wait-for-regexp (6) # 
t
/home/albinus/tmp/zzz
tramp_exit_status 0
///dd77c20acbfe3e98bd0661ddf70b1f4a#$
16:26:26.870794 tramp-send-command (6) # (if test -h "/home/albinus/tmp/zzz"; then echo t; else echo nil; fi) && \readlink --canonicalize-missing /home/albinus/tmp/zzz 2>/dev/null; echo tramp_exit_status $?
16:26:26.887610 tramp-wait-for-regexp (6) # 
t
/home/albinus/tmp/zzz
tramp_exit_status 0
///dd77c20acbfe3e98bd0661ddf70b1f4a#$
16:26:26.906448 tramp-send-command (6) # (if test -h "/home/albinus/tmp/zzz"; then echo t; else echo nil; fi) && \readlink --canonicalize-missing /home/albinus/tmp/zzz 2>/dev/null; echo tramp_exit_status $?
16:26:26.983946 tramp-wait-for-regexp (6) # 
t
/home/albinus/tmp/zzz
tramp_exit_status 0
///dd77c20acbfe3e98bd0661ddf70b1f4a#$
16:26:27.006076 tramp-send-command (6) # (if test -h "/home/albinus/tmp/zzz"; then echo t; else echo nil; fi) && \readlink --canonicalize-missing /home/albinus/tmp/zzz 2>/dev/null; echo tramp_exit_status $?
16:26:27.010734 tramp-wait-for-regexp (6) # 
t
/home/albinus/tmp/zzz
tramp_exit_status 0
///dd77c20acbfe3e98bd0661ddf70b1f4a#$
16:26:27.030175 tramp-send-command (6) # (if test -h "/home/albinus/tmp/zzz"; then echo t; else echo nil; fi) && \readlink --canonicalize-missing /home/albinus/tmp/zzz 2>/dev/null; echo tramp_exit_status $?
16:26:27.117633 tramp-wait-for-regexp (6) # 
t
/home/albinus/tmp/zzz
tramp_exit_status 0
///dd77c20acbfe3e98bd0661ddf70b1f4a#$
16:26:27.139885 tramp-send-command (6) # (if test -h "/home/albinus/tmp/zzz"; then echo t; else echo nil; fi) && \readlink --canonicalize-missing /home/albinus/tmp/zzz 2>/dev/null; echo tramp_exit_status $?
16:26:27.151833 tramp-wait-for-regexp (6) # 
t
/home/albinus/tmp/zzz
tramp_exit_status 0
///dd77c20acbfe3e98bd0661ddf70b1f4a#$
16:26:27.171011 tramp-send-command (6) # (if test -h "/home/albinus/tmp/zzz"; then echo t; else echo nil; fi) && \readlink --canonicalize-missing /home/albinus/tmp/zzz 2>/dev/null; echo tramp_exit_status $?
16:26:27.252462 tramp-wait-for-regexp (6) # 
t
/home/albinus/tmp/zzz
tramp_exit_status 0
///dd77c20acbfe3e98bd0661ddf70b1f4a#$
16:26:27.275070 tramp-send-command (6) # (if test -h "/home/albinus/tmp/zzz"; then echo t; else echo nil; fi) && \readlink --canonicalize-missing /home/albinus/tmp/zzz 2>/dev/null; echo tramp_exit_status $?
16:26:27.292574 tramp-wait-for-regexp (6) # 
t
/home/albinus/tmp/zzz
tramp_exit_status 0
///dd77c20acbfe3e98bd0661ddf70b1f4a#$
16:26:27.311554 tramp-send-command (6) # (if test -h "/home/albinus/tmp/zzz"; then echo t; else echo nil; fi) && \readlink --canonicalize-missing /home/albinus/tmp/zzz 2>/dev/null; echo tramp_exit_status $?
16:26:27.396961 tramp-wait-for-regexp (6) # 
t
/home/albinus/tmp/zzz
tramp_exit_status 0
///dd77c20acbfe3e98bd0661ddf70b1f4a#$
16:26:27.419460 tramp-send-command (6) # (if test -h "/home/albinus/tmp/zzz"; then echo t; else echo nil; fi) && \readlink --canonicalize-missing /home/albinus/tmp/zzz 2>/dev/null; echo tramp_exit_status $?
16:26:27.431578 tramp-wait-for-regexp (6) # 
t
/home/albinus/tmp/zzz
tramp_exit_status 0
///dd77c20acbfe3e98bd0661ddf70b1f4a#$
16:26:27.451191 tramp-send-command (6) # (if test -h "/home/albinus/tmp/zzz"; then echo t; else echo nil; fi) && \readlink --canonicalize-missing /home/albinus/tmp/zzz 2>/dev/null; echo tramp_exit_status $?
16:26:27.544333 tramp-wait-for-regexp (6) # 
t
/home/albinus/tmp/zzz
tramp_exit_status 0
///dd77c20acbfe3e98bd0661ddf70b1f4a#$
16:26:27.567437 tramp-send-command (6) # (if test -h "/home/albinus/tmp/zzz"; then echo t; else echo nil; fi) && \readlink --canonicalize-missing /home/albinus/tmp/zzz 2>/dev/null; echo tramp_exit_status $?
16:26:27.574681 tramp-wait-for-regexp (6) # 
t
/home/albinus/tmp/zzz
tramp_exit_status 0
///dd77c20acbfe3e98bd0661ddf70b1f4a#$
16:26:27.594068 tramp-send-command (6) # (if test -h "/home/albinus/tmp/zzz"; then echo t; else echo nil; fi) && \readlink --canonicalize-missing /home/albinus/tmp/zzz 2>/dev/null; echo tramp_exit_status $?
16:26:27.681818 tramp-wait-for-regexp (6) # 
t
/home/albinus/tmp/zzz
tramp_exit_status 0
///dd77c20acbfe3e98bd0661ddf70b1f4a#$
16:26:27.701140 tramp-sh-handle-file-truename (10) # 
  backtrace()
  tramp-sh-handle-file-truename("/ssh:gandalf:~/tmp/zzz")
  tramp-sh-file-name-handler(file-truename "/ssh:gandalf:~/tmp/zzz")
  apply(tramp-sh-file-name-handler file-truename "/ssh:gandalf:~/tmp/zzz")
  tramp-file-name-handler(file-truename "/ssh:gandalf:~/tmp/zzz")
  file-truename("/ssh:gandalf:~/tmp/zzz")
  #f(compiled-function (end) #<bytecode 0x109ac555a7b5f865>)(4481)
  font-lock-fontify-keywords-region(4398 4482 nil)
  font-lock-default-fontify-region(4481 4482 nil)
  font-lock-fontify-region(4481 4482)
  #f(compiled-function (fun) #<bytecode 0x1b89b6a5409e3f3f>)(font-lock-fontify-region)
  jit-lock--run-functions(4481 4482)
  jit-lock-fontify-now(4481 4482)
  jit-lock-function(4481)
  end-of-buffer(nil)
  funcall-interactively(end-of-buffer nil)
  command-execute(end-of-buffer)
16:26:27.701222 tramp-sh-handle-file-truename (1) # File error: Apparent cycle of symbolic links for /ssh:gandalf:~/tmp/zzz
t
/home/albinus/tmp/zzz
--8<---------------cut here---------------end--------------->8---

15 times the "test -h" command - I guess, Tramp shall do cyclic link
detection better.

Best regards, Michael.

bug#73046: 29.4; Emacs 100% CPU usage for several seconds when opening dired buffer over TRAMP

[Eli Zaretskii]

> From: Michael Albinus <michael.albinus@gmx.de>
> Cc: Suhail Singh <suhailsingh247@gmail.com>,  73046@debbugs.gnu.org
> Date: Sat, 07 Sep 2024 16:36:42 +0200
> 
> Eli Zaretskii <eliz@gnu.org> writes:
> 
> > Michael, what do these checks entail, and why are they so
> > CPU-expensive and take a lot of time with slow connections?
> 
> I made a test. In a remote directory I have created a cyclic symlink
> "zzz", in order to see what Tramp does when running dired on the
> directory. The additional actions are
> [...]
> 15 times the "test -h" command - I guess, Tramp shall do cyclic link
> detection better.

I agree.  But that only explains the time delay, no why Emacs is
consuming 100% of CPU, right?  Waiting for the network should not
consume CPU, unless I'm missing something.

Also, Suhail Singh says that there's a significant delay when there
are valid symlinks, in which case I don't expect Tramp to issue the
same command 15 times, right?

I'm sorry to insist on understanding these fine details, but my
experience is that without a good understanding of a problem we might
devise a solution that is only a partial one.

Thanks.

bug#73046: 29.4; Emacs 100% CPU usage for several seconds when opening dired buffer over TRAMP

[Suhail Singh]

Eli Zaretskii <eliz@gnu.org> writes:

>> 15 times the "test -h" command - I guess, Tramp shall do cyclic link
>> detection better.
>
> I agree.  But that only explains the time delay, no why Emacs is
> consuming 100% of CPU, right?  Waiting for the network should not
> consume CPU, unless I'm missing something.
>
> Also, Suhail Singh says that there's a significant delay when there
> are valid symlinks, in which case I don't expect Tramp to issue the
> same command 15 times, right?

Yes, while there are clearly inefficiencies in cyclic link detection,
that's not the situation for the reproducer I shared.  Font-locking
symlinks (broken, not broken; to files, to directories) trigger the
issue even without introducing cyclic references.  For what it's worth,
as I shared in an earlier exchange, the profiler-report seemed to point
the finger to `tramp-wait-for-regexp':

| Func in font-lock check | TRAMP handler                                                        |
|-------------------------+----------------------------------------------------------------------|
| `file-truename'         | `tramp-sh-handle-file-truename' -> ... -> `tramp-wait-for-regexp'    |
| `file-exists-p'         | `tramp-sh-handle-file-exists-p' -> ... -> `tramp-wait-for-regexp'    |
| `file-directory-p'      | `tramp-sh-handle-file-directory-p' -> ... -> `tramp-wait-for-regexp' |

Unless I misinterpreted the profiler output, something in/about
`tramp-wait-for-regexp' results in the 100% CPU usage.

-- 
Suhail

bug#73046: 29.4; Emacs 100% CPU usage for several seconds when opening dired buffer over TRAMP

[Michael Albinus via Bug reports for GNU Emacs, the Swiss army knife of text editors]

Suhail Singh <suhailsingh247@gmail.com> writes:

Hi,

>> I agree.  But that only explains the time delay, no why Emacs is
>> consuming 100% of CPU, right?  Waiting for the network should not
>> consume CPU, unless I'm missing something.
>>
>> Also, Suhail Singh says that there's a significant delay when there
>> are valid symlinks, in which case I don't expect Tramp to issue the
>> same command 15 times, right?
>
> Yes, while there are clearly inefficiencies in cyclic link detection,
> that's not the situation for the reproducer I shared.  Font-locking
> symlinks (broken, not broken; to files, to directories) trigger the
> issue even without introducing cyclic references.  For what it's worth,
> as I shared in an earlier exchange, the profiler-report seemed to point
> the finger to `tramp-wait-for-regexp':
>
> | Func in font-lock check | TRAMP handler                                                        |
> |-------------------------+----------------------------------------------------------------------|
> | `file-truename'         | `tramp-sh-handle-file-truename' -> ... -> `tramp-wait-for-regexp'    |
> | `file-exists-p'         | `tramp-sh-handle-file-exists-p' -> ... -> `tramp-wait-for-regexp'    |
> | `file-directory-p'      | `tramp-sh-handle-file-directory-p' -> ... -> `tramp-wait-for-regexp' |
>
> Unless I misinterpreted the profiler output, something in/about
> `tramp-wait-for-regexp' results in the 100% CPU usage.

Tramp is in a loop, waiting for results from the remote side. I don't
know how to implement this differently.

Best regards, Michael.

bug#73046: 29.4; Emacs 100% CPU usage for several seconds when opening dired buffer over TRAMP

[Eli Zaretskii]

> From: Michael Albinus <michael.albinus@gmx.de>
> Cc: Eli Zaretskii <eliz@gnu.org>,  73046@debbugs.gnu.org
> Date: Sun, 08 Sep 2024 13:30:00 +0200
> 
> Suhail Singh <suhailsingh247@gmail.com> writes:
> 
> > Unless I misinterpreted the profiler output, something in/about
> > `tramp-wait-for-regexp' results in the 100% CPU usage.
> 
> Tramp is in a loop, waiting for results from the remote side. I don't
> know how to implement this differently.

What kind of loop?  Can you point me to the code which loops there?

bug#73046: 29.4; Emacs 100% CPU usage for several seconds when opening dired buffer over TRAMP

[Michael Albinus via Bug reports for GNU Emacs, the Swiss army knife of text editors]

Eli Zaretskii <eliz@gnu.org> writes:

Hi Eli,

>> Tramp is in a loop, waiting for results from the remote side. I don't
>> know how to implement this differently.
>
> What kind of loop?  Can you point me to the code which loops there?

The umbrella function is tramp-send-command. It sends the command to
remote via tramp-send-string, and waits then for a proper shell prompt
via tramp-wait-for-output. The latter function calls
tramp-wait-for-regexp, which loops using tramp-accept-process-output.

Best regards, Michael.

bug#73046: 29.4; Emacs 100% CPU usage for several seconds when opening dired buffer over TRAMP

[Eli Zaretskii]

> From: Michael Albinus <michael.albinus@gmx.de>
> Cc: suhailsingh247@gmail.com,  73046@debbugs.gnu.org
> Date: Sun, 08 Sep 2024 17:26:40 +0200
> 
> Eli Zaretskii <eliz@gnu.org> writes:
> 
> >> Tramp is in a loop, waiting for results from the remote side. I don't
> >> know how to implement this differently.
> >
> > What kind of loop?  Can you point me to the code which loops there?
> 
> The umbrella function is tramp-send-command. It sends the command to
> remote via tramp-send-string, and waits then for a proper shell prompt
> via tramp-wait-for-output. The latter function calls
> tramp-wait-for-regexp, which loops using tramp-accept-process-output.

Did you try either calling accept-process-output with a non-zero
timeout of, say, 5 msec, or inserting a (sit-for 0.005) into the loop
which calls tramp-accept-process-output?

Waiting for a process to respond should try not to spin without
sleeping for a few milliseconds between polling attempts.

bug#73046: 29.4; Emacs 100% CPU usage for several seconds when opening dired buffer over TRAMP

[Suhail Singh]

Eli Zaretskii <eliz@gnu.org> writes:

>> >> Tramp is in a loop, waiting for results from the remote side. I don't
>> >> know how to implement this differently.
>> >
>> > What kind of loop?  Can you point me to the code which loops there?
>> 
>> The umbrella function is tramp-send-command. It sends the command to
>> remote via tramp-send-string, and waits then for a proper shell prompt
>> via tramp-wait-for-output. The latter function calls
>> tramp-wait-for-regexp, which loops using tramp-accept-process-output.
>
> Did you try either calling accept-process-output with a non-zero
> timeout of, say, 5 msec, or inserting a (sit-for 0.005) into the loop
> which calls tramp-accept-process-output?
>
> Waiting for a process to respond should try not to spin without
> sleeping for a few milliseconds between polling attempts.

A constant delay busy-wait would be better than what's there today.  A
straightforward exponential back-off (start with something small like
0.005 and double on each "still-waiting" case till something larger like
0.5) could be even better.

However, I thought you'd be proposing something like registering a
"callback".  Out of curiosity, since I am unfamiliar with the relevant
Emacs internals, would it not be possible to add a function to the
equivalent of `after-change-functions' that processes the output?

-- 
Suhail

bug#73046: 29.4; Emacs 100% CPU usage for several seconds when opening dired buffer over TRAMP

[Eli Zaretskii]

> From: Suhail Singh <suhailsingh247@gmail.com>
> Cc: Michael Albinus <michael.albinus@gmx.de>,  suhailsingh247@gmail.com,
>   73046@debbugs.gnu.org
> Date: Sun, 08 Sep 2024 12:46:39 -0400
> 
> Eli Zaretskii <eliz@gnu.org> writes:
> 
> > Waiting for a process to respond should try not to spin without
> > sleeping for a few milliseconds between polling attempts.
> 
> A constant delay busy-wait would be better than what's there today.

It isn't a delay, or at least the delay is not the main point.  The
main point is to yield the CPU, and that usually has dramatic effect
on CPU load.

> However, I thought you'd be proposing something like registering a
> "callback".  Out of curiosity, since I am unfamiliar with the relevant
> Emacs internals, would it not be possible to add a function to the
> equivalent of `after-change-functions' that processes the output?

accept-process-output already does that.  Except that with a timeout
of zero, it just checks whether any output arrived, and if not,
returns immediately.  Adding a timeout will AFAIU cause us to let the
OS preempt our execution thread and reschedule it only if no output
arrives during the timeout.

bug#73046: 29.4; Emacs 100% CPU usage for several seconds when opening dired buffer over TRAMP

[Michael Albinus via Bug reports for GNU Emacs, the Swiss army knife of text editors]

Eli Zaretskii <eliz@gnu.org> writes:

Hi Eli,

>> The umbrella function is tramp-send-command. It sends the command to
>> remote via tramp-send-string, and waits then for a proper shell prompt
>> via tramp-wait-for-output. The latter function calls
>> tramp-wait-for-regexp, which loops using tramp-accept-process-output.
>
> Did you try either calling accept-process-output with a non-zero
> timeout of, say, 5 msec, or inserting a (sit-for 0.005) into the loop
> which calls tramp-accept-process-output?

Tramp used a non-zero timeout in the past. This was removed some years
ago, I don't remember the reason.

I've added (sit-for 0.005) in the loop calling
tramp-accept-process-output. It decreases the CPU load from 100% to
something between 45..50%, when waiting for a response from
remote. Pushed to master, and thanks for the explanation!

Best regards, Michael.

bug#73046: 29.4; Emacs 100% CPU usage for several seconds when opening dired buffer over TRAMP

[Suhail Singh]

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

> Tramp used a non-zero timeout in the past. This was removed some years
> ago, I don't remember the reason.

The timeout in tramp-accept-process-output was disabled in commit
54ef338ba3670415cf47fabc33a92d4904707c7e .  The commit mentions
bug#61350 , however, it's not clear (based on briefly skimming the
discussion there) that this change was ever necessary.  If not, should
the timeout be reintroduced?

> I've added (sit-for 0.005) in the loop calling
> tramp-accept-process-output. It decreases the CPU load from 100% to
> something between 45..50%, when waiting for a response from remote.

I am trying to better understand what's going on, so the following is
simply for my understanding.  Use your discretion when responding.

IIUC, we're still actively waiting for the output from the remote host,
but simple not _exclusively_ doing so thanks to the `sit-for'.  Is my
understanding correct?  If so, isn't there some mechanism to specify a
continuation that's run once the TRAMP process produces output?  Such a
mechanism shouldn't require a `sit-for' to yield control.

In other words, isn't it possible to do both font-locking and getting
the response over ssh concurrently (of the main thread, as well wrt each
other)?  If not, are there technical challenges in doing so, or simply
that it's not been implemented (and thus, possibly, we may not know what
the challenges are)?

> Pushed to master

Thank you.  I can test this (applied onto 29.4) later in the week along
with the `dired-font-lock-keywords' patch and report back.

-- 
Suhail

bug#73046: 29.4; Emacs 100% CPU usage for several seconds when opening dired buffer over TRAMP

[Eli Zaretskii]

> From: Suhail Singh <suhailsingh247@gmail.com>
> Cc: Eli Zaretskii <eliz@gnu.org>,  suhailsingh247@gmail.com,
>   73046@debbugs.gnu.org
> Date: Tue, 10 Sep 2024 21:05:29 -0400
> 
> Michael Albinus <michael.albinus@gmx.de> writes:
> 
> > Tramp used a non-zero timeout in the past. This was removed some years
> > ago, I don't remember the reason.
> 
> The timeout in tramp-accept-process-output was disabled in commit
> 54ef338ba3670415cf47fabc33a92d4904707c7e .  The commit mentions
> bug#61350 , however, it's not clear (based on briefly skimming the
> discussion there) that this change was ever necessary.  If not, should
> the timeout be reintroduced?

I think Michael just did (see below).

> IIUC, we're still actively waiting for the output from the remote host,
> but simple not _exclusively_ doing so thanks to the `sit-for'.  Is my
> understanding correct?

When we call sit-for, we yield the CPU for whatever other jobs are
waiting, so we don't hog the processor.

> If so, isn't there some mechanism to specify a
> continuation that's run once the TRAMP process produces output?  Such a
> mechanism shouldn't require a `sit-for' to yield control.

How would that help?  Tramp must still wait for the response to
proceed with what it does.

> In other words, isn't it possible to do both font-locking and getting
> the response over ssh concurrently (of the main thread, as well wrt each
> other)?

Every Lisp program runs in a single thread, so how can that be done in
parallel?

> If not, are there technical challenges in doing so, or simply that
> it's not been implemented (and thus, possibly, we may not know what
> the challenges are)?

Emacs doesn't support parallel processing, because introducing this
into the original single-threaded design is very hard at best, due to
a huge global state.  We have Lisp threads, but only one thread can
run at any given time.

> > Pushed to master
> 
> Thank you.  I can test this (applied onto 29.4) later in the week along
> with the `dired-font-lock-keywords' patch and report back.

Thanks.

bug#73046: 29.4; Emacs 100% CPU usage for several seconds when opening dired buffer over TRAMP

[Suhail Singh]

Eli Zaretskii <eliz@gnu.org> writes:

>> If so, isn't there some mechanism to specify a
>> continuation that's run once the TRAMP process produces output?  Such a
>> mechanism shouldn't require a `sit-for' to yield control.
>
> How would that help?  Tramp must still wait for the response to
> proceed with what it does.
>
>> In other words, isn't it possible to do both font-locking and getting
>> the response over ssh concurrently (of the main thread, as well wrt each
>> other)?
>
> Every Lisp program runs in a single thread, so how can that be done in
> parallel?
>
>> If not, are there technical challenges in doing so, or simply that
>> it's not been implemented (and thus, possibly, we may not know what
>> the challenges are)?
>
> Emacs doesn't support parallel processing, because introducing this
> into the original single-threaded design is very hard at best, due to
> a huge global state.  We have Lisp threads, but only one thread can
> run at any given time.

I was imagining a version of TRAMP that was asynchronous.  I understand
now that it isn't.

-- 
Suhail

bug#73046: 29.4; Emacs 100% CPU usage for several seconds when opening dired buffer over TRAMP

[Michael Albinus via Bug reports for GNU Emacs, the Swiss army knife of text editors]

Suhail Singh <suhailsingh247@gmail.com> writes:

Hi Suhail,

> I was imagining a version of TRAMP that was asynchronous.  I understand
> now that it isn't.

FTR, some years ago (2018?) I tried to use Lisp threads with Tramp. This
experiment failed.

Best regards, Michael.

bug#73046: 29.4; Emacs 100% CPU usage for several seconds when opening dired buffer over TRAMP

[Suhail Singh]

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

> FTR, some years ago (2018?) I tried to use Lisp threads with Tramp. This
> experiment failed.

OOC, the failure was from hard-to-debug edge cases while trying to get
to feature-parity or something else?

-- 
Suhail

bug#73046: 29.4; Emacs 100% CPU usage for several seconds when opening dired buffer over TRAMP

[Michael Albinus via Bug reports for GNU Emacs, the Swiss army knife of text editors]

Suhail Singh <suhailsingh247@gmail.com> writes:

Hi Suhail,

>> FTR, some years ago (2018?) I tried to use Lisp threads with Tramp. This
>> experiment failed.
>
> OOC, the failure was from hard-to-debug edge cases while trying to get
> to feature-parity or something else?

IIRC, the major problem were interactive dialogues. See bug#32426 and
bug#25214.

Best regards, Michael.

bug#73046: 29.4; Emacs 100% CPU usage for several seconds when opening dired buffer over TRAMP

[Michael Albinus via Bug reports for GNU Emacs, the Swiss army knife of text editors]

Suhail Singh <suhailsingh247@gmail.com> writes:

Hi Suhail,

>> Tramp used a non-zero timeout in the past. This was removed some years
>> ago, I don't remember the reason.
>
> The timeout in tramp-accept-process-output was disabled in commit
> 54ef338ba3670415cf47fabc33a92d4904707c7e .  The commit mentions
> bug#61350 , however, it's not clear (based on briefly skimming the
> discussion there) that this change was ever necessary.  If not, should
> the timeout be reintroduced?

tramp-accept-process-output has seen several changes over the last 19
years. Some of them with collateral damages in edge cases, which needed
another fix then.

I'm happy it works stable now, and I'm reluctant to touch it w/o urgent
need. That's why I have used the (sit-for 0.005) solution proposed by
Eli, outside tramp-accept-process-output.

Best regards, Michael.

bug#73046: 29.4; Emacs 100% CPU usage for several seconds when opening dired buffer over TRAMP

[Suhail Singh]

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

> I'm happy it works stable now, and I'm reluctant to touch it w/o urgent
> need. That's why I have used the (sit-for 0.005) solution proposed by
> Eli, outside tramp-accept-process-output.

Understood; thanks for elaborating.

-- 
Suhail

bug#73046: 29.4; Emacs 100% CPU usage for several seconds when opening dired buffer over TRAMP

[Suhail Singh]

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

> I've added (sit-for 0.005) in the loop calling
> tramp-accept-process-output. It decreases the CPU load from 100% to
> something between 45..50%, when waiting for a response from
> remote. Pushed to master

I tested this patch today atop TRAMP 2.7.1.2.  Some findings:

1. If directory with symlinks on remote host with slow connection is
   opened CPU usage is much less than 100%.  That's the good news.
   However, there are a couple of caveats.

2. If we are in parent directory, and soon after pressing RET we invoke
   M-x we don't see the minibuffer prompt till after the offending
   directory has finished font-locking.

3. If after invoking M-x we immediately start typing, the keyboard input
   is registered, however, it doesn't display in the minibuffer till
   after the offending directory has finished font-locking.
   Additionally, doing so invariably results in 100% CPU usage for the
   duration of the font-locking.  Sometimes invoking M-x alone results
   in CPU usage going back up to 100% (while font-locking is still being
   done).

Thoughts?

-- 
Suhail

bug#73046: 29.4; Emacs 100% CPU usage for several seconds when opening dired buffer over TRAMP

[Eli Zaretskii]

> From: Suhail Singh <suhailsingh247@gmail.com>
> Cc: Eli Zaretskii <eliz@gnu.org>,  suhailsingh247@gmail.com,
>   73046@debbugs.gnu.org
> Date: Fri, 13 Sep 2024 19:17:36 -0400
> 
> Michael Albinus <michael.albinus@gmx.de> writes:
> 
> > I've added (sit-for 0.005) in the loop calling
> > tramp-accept-process-output. It decreases the CPU load from 100% to
> > something between 45..50%, when waiting for a response from
> > remote. Pushed to master
> 
> I tested this patch today atop TRAMP 2.7.1.2.  Some findings:
> 
> 1. If directory with symlinks on remote host with slow connection is
>    opened CPU usage is much less than 100%.  That's the good news.
>    However, there are a couple of caveats.
> 
> 2. If we are in parent directory, and soon after pressing RET we invoke
>    M-x we don't see the minibuffer prompt till after the offending
>    directory has finished font-locking.
> 
> 3. If after invoking M-x we immediately start typing, the keyboard input
>    is registered, however, it doesn't display in the minibuffer till
>    after the offending directory has finished font-locking.
>    Additionally, doing so invariably results in 100% CPU usage for the
>    duration of the font-locking.  Sometimes invoking M-x alone results
>    in CPU usage going back up to 100% (while font-locking is still being
>    done).
> 
> Thoughts?

Are 2 and 3 new with this patch, or were they present in the previous
code as well?

And what do you expect to happen when you press M-x while Emacs is
still busy performing your previous command?  Having the visual
response delayed until the previous command finishes is normal Emacs
behavior, being a single-threaded program which executes commands one
by one in the same thread.

bug#73046: 29.4; Emacs 100% CPU usage for several seconds when opening dired buffer over TRAMP

[Suhail Singh]

Eli Zaretskii <eliz@gnu.org> writes:

>> 2. If we are in parent directory, and soon after pressing RET we invoke
>>    M-x we don't see the minibuffer prompt till after the offending
>>    directory has finished font-locking.
>> 
>> 3. If after invoking M-x we immediately start typing, the keyboard input
>>    is registered, however, it doesn't display in the minibuffer till
>>    after the offending directory has finished font-locking.
>>    Additionally, doing so invariably results in 100% CPU usage for the
>>    duration of the font-locking.  Sometimes invoking M-x alone results
>>    in CPU usage going back up to 100% (while font-locking is still being
>>    done).
>> 
>> Thoughts?
>
> Are 2 and 3 new with this patch, or were they present in the previous
> code as well?

Present prior to the patch as well.

> And what do you expect to happen when you press M-x while Emacs is
> still busy performing your previous command?

I did not have any expectations wrt 2.  I knew that it was possible that
2 was simply a limitation of the single-threaded reality of the current
implementation.  However, it wasn't clear (till now) whether that was
necessarily the case.

I did not expect 3 to happen.  I.e., wrt 3 my expectation was that
invoking M-x and typing doesn't result in a noticable increase in CPU
usage for the duration of the font-locking.

> Having the visual response delayed until the previous command finishes
> is normal Emacs behavior, being a single-threaded program which
> executes commands one by one in the same thread.

Understood.

-- 
Suhail

bug#73046: 29.4; Emacs 100% CPU usage for several seconds when opening dired buffer over TRAMP

[Suhail Singh]

Suhail Singh <suhailsingh247@gmail.com> writes:

>>> 2. If we are in parent directory, and soon after pressing RET we invoke
>>>    M-x we don't see the minibuffer prompt till after the offending
>>>    directory has finished font-locking.
>>> 
>>> 3. If after invoking M-x we immediately start typing, the keyboard input
>>>    is registered, however, it doesn't display in the minibuffer till
>>>    after the offending directory has finished font-locking.
>>>    Additionally, doing so invariably results in 100% CPU usage for the
>>>    duration of the font-locking.  Sometimes invoking M-x alone results
>>>    in CPU usage going back up to 100% (while font-locking is still being
>>>    done).
>>> 
>>> Thoughts?
>>
>> Are 2 and 3 new with this patch, or were they present in the previous
>> code as well?
>
> Present prior to the patch as well.

To be more accurate, 2 was present prior to the patch.  3 was
unobservable, because prior to the patch CPU usage was at 100%
throughout (regardless of invoking M-x and typing some keys or not).

-- 
Suhail

bug#73046: 29.4; Emacs 100% CPU usage for several seconds when opening dired buffer over TRAMP

[Eli Zaretskii]

> From: Suhail Singh <suhailsingh247@gmail.com>
> Cc: Suhail Singh <suhailsingh247@gmail.com>,  michael.albinus@gmx.de,
>   73046@debbugs.gnu.org
> Date: Sat, 14 Sep 2024 10:25:13 -0400
> 
> Eli Zaretskii <eliz@gnu.org> writes:
> 
> >> 3. If after invoking M-x we immediately start typing, the keyboard input
> >>    is registered, however, it doesn't display in the minibuffer till
> >>    after the offending directory has finished font-locking.
> >>    Additionally, doing so invariably results in 100% CPU usage for the
> >>    duration of the font-locking.  Sometimes invoking M-x alone results
> >>    in CPU usage going back up to 100% (while font-locking is still being
> >>    done).
> >> 
> >> Thoughts?
> >
> > Are 2 and 3 new with this patch, or were they present in the previous
> > code as well?
> 
> Present prior to the patch as well.
> 
> > And what do you expect to happen when you press M-x while Emacs is
> > still busy performing your previous command?
> 
> I did not have any expectations wrt 2.  I knew that it was possible that
> 2 was simply a limitation of the single-threaded reality of the current
> implementation.  However, it wasn't clear (till now) whether that was
> necessarily the case.
> 
> I did not expect 3 to happen.  I.e., wrt 3 my expectation was that
> invoking M-x and typing doesn't result in a noticable increase in CPU
> usage for the duration of the font-locking.

If 3 surprised you, then the reason is simple: sit-for returns
immediately if any input is available, so typing effectively disables
the wait.  This could be countermanded by unconditional sleep, but
AFAIU Michael is rethinking the whole issue, so we should wait for him
to reach his conclusions.

In any case, interrupting the wait when you type makes sense in
general: it means Emacs is expected to respond sooner, which in most
cases indeed means to stop waiting immediately.

bug#73046: 29.4; Emacs 100% CPU usage for several seconds when opening dired buffer over TRAMP

[Suhail Singh]

Eli Zaretskii <eliz@gnu.org> writes:

> If 3 surprised you, then the reason is simple: sit-for returns
> immediately if any input is available, so typing effectively disables
> the wait.

Interesting.  I didn't expect it to do so persistently (i.e., for
subsequent iterations of the while loop in question).

> This could be countermanded by unconditional sleep, but AFAIU Michael
> is rethinking the whole issue, so we should wait for him to reach his
> conclusions.

Agreed.

-- 
Suhail

bug#73046: 29.4; Emacs 100% CPU usage for several seconds when opening dired buffer over TRAMP

[Eli Zaretskii]

> From: Suhail Singh <suhailsingh247@gmail.com>
> Cc: Suhail Singh <suhailsingh247@gmail.com>,  michael.albinus@gmx.de,
>   73046@debbugs.gnu.org
> Date: Sat, 14 Sep 2024 18:36:04 -0400
> 
> Eli Zaretskii <eliz@gnu.org> writes:
> 
> > If 3 surprised you, then the reason is simple: sit-for returns
> > immediately if any input is available, so typing effectively disables
> > the wait.
> 
> Interesting.  I didn't expect it to do so persistently (i.e., for
> subsequent iterations of the while loop in question).

Since the command still runs, your type-ahead is not consumed, and
each sit-for exits immediately.

bug#73046: 29.4; Emacs 100% CPU usage for several seconds when opening dired buffer over TRAMP

[Suhail Singh]

Eli Zaretskii <eliz@gnu.org> writes:

> Since the command still runs, your type-ahead is not consumed, and
> each sit-for exits immediately.

Ah!  Thank you for explaining.

-- 
Suhail

bug#73046: 29.4; Emacs 100% CPU usage for several seconds when opening dired buffer over TRAMP

[Michael Albinus via Bug reports for GNU Emacs, the Swiss army knife of text editors]

Eli Zaretskii <eliz@gnu.org> writes:

Hi,

> If 3 surprised you, then the reason is simple: sit-for returns
> immediately if any input is available, so typing effectively disables
> the wait.  This could be countermanded by unconditional sleep, but
> AFAIU Michael is rethinking the whole issue, so we should wait for him
> to reach his conclusions.
>
> In any case, interrupting the wait when you type makes sense in
> general: it means Emacs is expected to respond sooner, which in most
> cases indeed means to stop waiting immediately.

I played with the different configurations to use sit-for. The test
scenario is simple and can be reproduced with any remote connection, be
it slow or fast:

--8<---------------cut here---------------start------------->8---
emacs -Q /ssh:remotehost:
M-! sleep 30
--8<---------------cut here---------------end--------------->8---

This starts a synchronous remote shell-command, and Tramp must wait for
the response in order to return the exit code (akways 9 in this
scenario). Observe the Emacs resource consumption by 'top' in another shell.

As a second test, I use the Tramp test suite in order to see whether
there is performance degradation. It is sufficient to run the test cases
tramp-test11-copy-file and tramp-test12-rename-file.

make -C test tramp-tests SELECTOR='"11\\|12"'

1. No sit-for call at all, as it has been the case when Suhail reported
the problem.

Emacs consumes 99% .. 100% CPU. The test suite reports

--8<---------------cut here---------------start------------->8---
   passed  1/2  tramp-test11-copy-file (1.645027 sec)
   passed  2/2  tramp-test12-rename-file (2.172439 sec)
--8<---------------cut here---------------end--------------->8---

2. Use (sit-for 0.005) in `tramp-wait-for-regexp', as done initially
with my patch.

Emacs consumes 42% .. 47% CPU. Good. However, the test suite reports

--8<---------------cut here---------------start------------->8---
   passed  1/2  tramp-test11-copy-file (5.311830 sec)
   passed  2/2  tramp-test12-rename-file (4.451581 sec)
--8<---------------cut here---------------end--------------->8---

This is a serious performance degradation, which isn't acceptable I
believe.

3. Use (sit-for 0.00005) in `tramp-wait-for-regexp', a much shorter timeout.

Emacs consumes 72% .. 74% CPU. Not ideal, but better than 100%. The test suite reports

--8<---------------cut here---------------start------------->8---
   passed  1/2  tramp-test11-copy-file (1.643277 sec)
   passed  2/2  tramp-test12-rename-file (1.800990 sec)
--8<---------------cut here---------------end--------------->8---

This is comparable to the initial values (there's always a small
difference).

4. Use (sit-for 0) in `tramp-wait-for-regexp'.

Emacs consumes 72% .. 74% CPU, the same as in 3. The test suite reports

--8<---------------cut here---------------start------------->8---
   passed  1/2  tramp-test11-copy-file (1.562353 sec)
   passed  2/2  tramp-test12-rename-file (1.626922 sec)
--8<---------------cut here---------------end--------------->8---

Seems to be the best compromise, I'm in the mood to apply.

Comments?

Best regards, Michael.

bug#73046: 29.4; Emacs 100% CPU usage for several seconds when opening dired buffer over TRAMP

[Eli Zaretskii]

> From: Michael Albinus <michael.albinus@gmx.de>
> Cc: Suhail Singh <suhailsingh247@gmail.com>,  73046@debbugs.gnu.org
> Date: Fri, 20 Sep 2024 11:54:28 +0200
> 
> 4. Use (sit-for 0) in `tramp-wait-for-regexp'.
> 
> Emacs consumes 72% .. 74% CPU, the same as in 3. The test suite reports
> 
> --8<---------------cut here---------------start------------->8---
>    passed  1/2  tramp-test11-copy-file (1.562353 sec)
>    passed  2/2  tramp-test12-rename-file (1.626922 sec)
> --8<---------------cut here---------------end--------------->8---
> 
> Seems to be the best compromise, I'm in the mood to apply.

Using (sit-for 0) is IMO okay, it means Emacs is yielding its CPU
slice, but is ready to run immediately after that.

bug#73046: 29.4; Emacs 100% CPU usage for several seconds when opening dired buffer over TRAMP

[Suhail Singh]

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

> 4. Use (sit-for 0) in `tramp-wait-for-regexp'.
>
> Emacs consumes 72% .. 74% CPU, the same as in 3. The test suite reports
>
>    passed  1/2  tramp-test11-copy-file (1.562353 sec)
>    passed  2/2  tramp-test12-rename-file (1.626922 sec)
>
> Seems to be the best compromise, I'm in the mood to apply.
>
> Comments?

Seems like a reasonable compromise.

On a related, but distinct note, thoughts on whether there's a
relatively straightforward way to address "3" below (from one of the
other exchanges in this thread)?

Eli Zaretskii <eliz@gnu.org> writes:

>> From: Suhail Singh <suhailsingh247@gmail.com>
>> Cc: Suhail Singh <suhailsingh247@gmail.com>,  michael.albinus@gmx.de,
>>   73046@debbugs.gnu.org
>> Date: Sat, 14 Sep 2024 10:25:13 -0400
>> 
>> Eli Zaretskii <eliz@gnu.org> writes:
>> 
>> >> 3. If after invoking M-x we immediately start typing, the keyboard input
>> >>    is registered, however, it doesn't display in the minibuffer till
>> >>    after the offending directory has finished font-locking.
>> >>    Additionally, doing so invariably results in 100% CPU usage for the
>> >>    duration of the font-locking.  Sometimes invoking M-x alone results
>> >>    in CPU usage going back up to 100% (while font-locking is still being
>> >>    done).
>> >> 
>> >> Thoughts?
>> >
>> > Are 2 and 3 new with this patch, or were they present in the previous
>> > code as well?
>> 
>> Present prior to the patch as well.
>> 
>> > And what do you expect to happen when you press M-x while Emacs is
>> > still busy performing your previous command?
>> 
>> I did not expect 3 to happen.  I.e., wrt 3 my expectation was that
>> invoking M-x and typing doesn't result in a noticable increase in CPU
>> usage for the duration of the font-locking.
>
> If 3 surprised you, then the reason is simple: sit-for returns
> immediately if any input is available, so typing effectively disables
> the wait.  This could be countermanded by unconditional sleep, but
> AFAIU Michael is rethinking the whole issue, so we should wait for him
> to reach his conclusions.


-- 
Suhail

bug#73046: 29.4; Emacs 100% CPU usage for several seconds when opening dired buffer over TRAMP

[Michael Albinus via Bug reports for GNU Emacs, the Swiss army knife of text editors]

Suhail Singh <suhailsingh247@gmail.com> writes:

Hi Suhail,

> On a related, but distinct note, thoughts on whether there's a
> relatively straightforward way to address "3" below (from one of the
> other exchanges in this thread)?
>
>>> >> 3. If after invoking M-x we immediately start typing, the keyboard input
>>> >>    is registered, however, it doesn't display in the minibuffer till
>>> >>    after the offending directory has finished font-locking.
>>> >>    Additionally, doing so invariably results in 100% CPU usage for the
>>> >>    duration of the font-locking.  Sometimes invoking M-x alone results
>>> >>    in CPU usage going back up to 100% (while font-locking is still being
>>> >>    done).
>>>
>>> > And what do you expect to happen when you press M-x while Emacs is
>>> > still busy performing your previous command?
>>>
>>> I did not expect 3 to happen.  I.e., wrt 3 my expectation was that
>>> invoking M-x and typing doesn't result in a noticable increase in CPU
>>> usage for the duration of the font-locking.
>>
>> If 3 surprised you, then the reason is simple: sit-for returns
>> immediately if any input is available, so typing effectively disables
>> the wait.  This could be countermanded by unconditional sleep, but
>> AFAIU Michael is rethinking the whole issue, so we should wait for him
>> to reach his conclusions.

This would mean to use (sleep-for 0) instead of (sit-for 0), right? Hmm,
I might try the same tests for this clause next days, no idea whether it
makes a difference.

But ATM, we should use (sit-for 0), until we know better.

Best regards, Michael.

bug#73046: 29.4; Emacs 100% CPU usage for several seconds when opening dired buffer over TRAMP

[Suhail Singh]

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

>>> If 3 surprised you, then the reason is simple: sit-for returns
>>> immediately if any input is available, so typing effectively disables
>>> the wait.  This could be countermanded by unconditional sleep, but
>>> AFAIU Michael is rethinking the whole issue, so we should wait for him
>>> to reach his conclusions.
>
> This would mean to use (sleep-for 0) instead of (sit-for 0), right? Hmm,
> I might try the same tests for this clause next days, no idea whether it
> makes a difference.
>
> But ATM, we should use (sit-for 0), until we know better.

I'll defer to your and Eli's expertise.  I don't have strong opinions on
the matter; I simply wanted to make sure you were aware of it.

Glad you're feeling better.

Regards,
-- 
Suhail

bug#73046: 29.4; Emacs 100% CPU usage for several seconds when opening dired buffer over TRAMP

[Michael Albinus via Bug reports for GNU Emacs, the Swiss army knife of text editors]

Version: 31.1

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

Hi Suhail,

>> On a related, but distinct note, thoughts on whether there's a
>> relatively straightforward way to address "3" below (from one of the
>> other exchanges in this thread)?
>>
>>>> >> 3. If after invoking M-x we immediately start typing, the keyboard input
>>>> >>    is registered, however, it doesn't display in the minibuffer till
>>>> >>    after the offending directory has finished font-locking.
>>>> >>    Additionally, doing so invariably results in 100% CPU usage for the
>>>> >>    duration of the font-locking.  Sometimes invoking M-x alone results
>>>> >>    in CPU usage going back up to 100% (while font-locking is still being
>>>> >>    done).
>>>>
>>>> > And what do you expect to happen when you press M-x while Emacs is
>>>> > still busy performing your previous command?
>>>>
>>>> I did not expect 3 to happen.  I.e., wrt 3 my expectation was that
>>>> invoking M-x and typing doesn't result in a noticable increase in CPU
>>>> usage for the duration of the font-locking.
>>>
>>> If 3 surprised you, then the reason is simple: sit-for returns
>>> immediately if any input is available, so typing effectively disables
>>> the wait.  This could be countermanded by unconditional sleep, but
>>> AFAIU Michael is rethinking the whole issue, so we should wait for him
>>> to reach his conclusions.
>
> This would mean to use (sleep-for 0) instead of (sit-for 0), right? Hmm,
> I might try the same tests for this clause next days, no idea whether it
> makes a difference.
>
> But ATM, we should use (sit-for 0), until we know better.

I've tried (sleep-for 0), but this doesn't help. CPU load is always 100%,
even if there is no input.

So I've pushed (sit-for 0) to master. Unless Eli has a better proposal,
I'm done with this.

It will also be available in Tramp 2.7.1.3, scheduled for release on GNU
ELPA end of this month.

Closing the bug.

Best regards, Michael.

bug#73046: 29.4; Emacs 100% CPU usage for several seconds when opening dired buffer over TRAMP

[Suhail Singh]

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

> It will also be available in Tramp 2.7.1.3, scheduled for release on GNU
> ELPA end of this month.
>
> Closing the bug.

Much appreciated; thanks!

-- 
Suhail

bug#73046: 29.4; Emacs 100% CPU usage for several seconds when opening dired buffer over TRAMP

[Michael Albinus via Bug reports for GNU Emacs, the Swiss army knife of text editors]

Suhail Singh <suhailsingh247@gmail.com> writes:

Hi Suhail,

>> I've added (sit-for 0.005) in the loop calling
>> tramp-accept-process-output. It decreases the CPU load from 100% to
>> something between 45..50%, when waiting for a response from
>> remote. Pushed to master
>
> I tested this patch today atop TRAMP 2.7.1.2.  Some findings:
>
> 1. If directory with symlinks on remote host with slow connection is
>    opened CPU usage is much less than 100%.  That's the good news.
>    However, there are a couple of caveats.

But there is also the message from Jake Nelson, reporting problems with
the (sit-for ...) clause.

Yesterday, I ran some regression tests. When (sit-for ...) is activated,
there are serious performance degadations. So I've deactivated it in
master; it must be revised more carefully before activating it, again.

>
> 2. If we are in parent directory, and soon after pressing RET we invoke
>    M-x we don't see the minibuffer prompt till after the offending
>    directory has finished font-locking.
>
> 3. If after invoking M-x we immediately start typing, the keyboard input
>    is registered, however, it doesn't display in the minibuffer till
>    after the offending directory has finished font-locking.
>    Additionally, doing so invariably results in 100% CPU usage for the
>    duration of the font-locking.  Sometimes invoking M-x alone results
>    in CPU usage going back up to 100% (while font-locking is still being
>    done).
>
> Thoughts?

No. Yesterday evening, my doctor started a new torture with me. This
will last about a week; I fear I cannot work during that time. Sorry.

Best regards, Michael.

bug#73046: 29.4; Emacs 100% CPU usage for several seconds when opening dired buffer over TRAMP

[Suhail Singh]

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

>> I tested this patch today atop TRAMP 2.7.1.2.  Some findings:
>>
>> 1. If directory with symlinks on remote host with slow connection is
>>    opened CPU usage is much less than 100%.  That's the good news.
>>    However, there are a couple of caveats.
>
> But there is also the message from Jake Nelson, reporting problems with
> the (sit-for ...) clause.

Could you please share the reference to that message (at your
convenience)?

> Yesterday, I ran some regression tests. When (sit-for ...) is activated,
> there are serious performance degadations. So I've deactivated it in
> master; it must be revised more carefully before activating it, again.

That's my impression as well.

>> 2. If we are in parent directory, and soon after pressing RET we invoke
>>    M-x we don't see the minibuffer prompt till after the offending
>>    directory has finished font-locking.
>>
>> 3. If after invoking M-x we immediately start typing, the keyboard input
>>    is registered, however, it doesn't display in the minibuffer till
>>    after the offending directory has finished font-locking.
>>    Additionally, doing so invariably results in 100% CPU usage for the
>>    duration of the font-locking.  Sometimes invoking M-x alone results
>>    in CPU usage going back up to 100% (while font-locking is still being
>>    done).
>>
>> Thoughts?
>
> No. Yesterday evening, my doctor started a new torture with me. This
> will last about a week; I fear I cannot work during that time. Sorry.

I hope it all goes well; get well soon!

Please take your time on this.  The `dired-font-lock-keywords' tweak
effectively reduces the severity of the issue.  When you do have an
updated patch, I'll be happy to run some tests as needed.

Regards,
-- 
Suhail

bug#73046: 29.4; Emacs 100% CPU usage for several seconds when opening dired buffer over TRAMP

[Michael Albinus via Bug reports for GNU Emacs, the Swiss army knife of text editors]

Suhail Singh <suhailsingh247@gmail.com> writes:

Hi Suhail,

>> But there is also the message from Jake Nelson, reporting problems with
>> the (sit-for ...) clause.
>
> Could you please share the reference to that message (at your
> convenience)?

<https://debbugs.gnu.org/cgi/bugreport.cgi?bug=73046#140>

> Regards,

Best regards, Michael.

bug#73046: 29.4; Emacs 100% CPU usage for several seconds when opening dired buffer over TRAMP

[Michael Albinus via Bug reports for GNU Emacs, the Swiss army knife of text editors]

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

Hi Eli,

> I made a test. In a remote directory I have created a cyclic symlink
> "zzz", in order to see what Tramp does when running dired on the
> directory. The additional actions are

[...]

> 15 times the "test -h" command - I guess, Tramp shall do cyclic link
> detection better.

I've analyzed the case in detail. Tracing file-truename and
tramp-sh-handle-file-truename.

--8<---------------cut here---------------start------------->8---
======================================================================
1 -> (file-truename "/ssh:gandalf:~/tmp/zzz")
| 2 -> (tramp-sh-handle-file-truename "/ssh:gandalf:~/tmp/zzz")
| 2 <- tramp-sh-handle-file-truename: !non-local\ exit!
1 <- file-truename: !non-local\ exit!
======================================================================
1 -> (file-truename "/ssh:gandalf:~/tmp/zzz")
| 2 -> (tramp-sh-handle-file-truename "/ssh:gandalf:~/tmp/zzz")
| 2 <- tramp-sh-handle-file-truename: !non-local\ exit!
1 <- file-truename: !non-local\ exit!
======================================================================
1 -> (file-truename "/ssh:gandalf:~/tmp/zzz")
| 2 -> (tramp-sh-handle-file-truename "/ssh:gandalf:~/tmp/zzz")
| 2 <- tramp-sh-handle-file-truename: !non-local\ exit!
1 <- file-truename: !non-local\ exit!
======================================================================
1 -> (file-truename "/ssh:gandalf:~/tmp/zzz")
| 2 -> (tramp-sh-handle-file-truename "/ssh:gandalf:~/tmp/zzz")
| 2 <- tramp-sh-handle-file-truename: !non-local\ exit!
1 <- file-truename: !non-local\ exit!
======================================================================
1 -> (file-truename "/ssh:gandalf:~/tmp/zzz")
| 2 -> (tramp-sh-handle-file-truename "/ssh:gandalf:~/tmp/zzz")
| 2 <- tramp-sh-handle-file-truename: !non-local\ exit!
1 <- file-truename: !non-local\ exit!
======================================================================
1 -> (file-truename "/ssh:gandalf:~/tmp/zzz")
| 2 -> (tramp-sh-handle-file-truename "/ssh:gandalf:~/tmp/zzz")
| 2 <- tramp-sh-handle-file-truename: !non-local\ exit!
1 <- file-truename: !non-local\ exit!
======================================================================
1 -> (file-truename "/ssh:gandalf:~/tmp/zzz")
| 2 -> (tramp-sh-handle-file-truename "/ssh:gandalf:~/tmp/zzz")
| 2 <- tramp-sh-handle-file-truename: !non-local\ exit!
1 <- file-truename: !non-local\ exit!
======================================================================
1 -> (file-truename "/ssh:gandalf:~/tmp/zzz")
| 2 -> (tramp-sh-handle-file-truename "/ssh:gandalf:~/tmp/zzz")
| 2 <- tramp-sh-handle-file-truename: !non-local\ exit!
1 <- file-truename: !non-local\ exit!
======================================================================
1 -> (file-truename "/ssh:gandalf:~/tmp/zzz")
| 2 -> (tramp-sh-handle-file-truename "/ssh:gandalf:~/tmp/zzz")
| 2 <- tramp-sh-handle-file-truename: !non-local\ exit!
1 <- file-truename: !non-local\ exit!
======================================================================
1 -> (file-truename "/ssh:gandalf:~/tmp/zzz")
| 2 -> (tramp-sh-handle-file-truename "/ssh:gandalf:~/tmp/zzz")
| 2 <- tramp-sh-handle-file-truename: !non-local\ exit!
1 <- file-truename: !non-local\ exit!
======================================================================
1 -> (file-truename "/ssh:gandalf:~/tmp/zzz")
| 2 -> (tramp-sh-handle-file-truename "/ssh:gandalf:~/tmp/zzz")
| 2 <- tramp-sh-handle-file-truename: !non-local\ exit!
1 <- file-truename: !non-local\ exit!
======================================================================
1 -> (file-truename "/ssh:gandalf:~/tmp/zzz")
| 2 -> (tramp-sh-handle-file-truename "/ssh:gandalf:~/tmp/zzz")
| 2 <- tramp-sh-handle-file-truename: !non-local\ exit!
1 <- file-truename: !non-local\ exit!
======================================================================
1 -> (file-truename "/ssh:gandalf:~/tmp/zzz")
| 2 -> (tramp-sh-handle-file-truename "/ssh:gandalf:~/tmp/zzz")
| 2 <- tramp-sh-handle-file-truename: !non-local\ exit!
1 <- file-truename: !non-local\ exit!
======================================================================
1 -> (file-truename "/ssh:gandalf:~/tmp/zzz")
| 2 -> (tramp-sh-handle-file-truename "/ssh:gandalf:~/tmp/zzz")
| 2 <- tramp-sh-handle-file-truename: !non-local\ exit!
1 <- file-truename: !non-local\ exit!
======================================================================
1 -> (file-truename "/ssh:gandalf:~/tmp/zzz")
| 2 -> (tramp-sh-handle-file-truename "/ssh:gandalf:~/tmp/zzz")
| 2 <- tramp-sh-handle-file-truename: !non-local\ exit!
1 <- file-truename: !non-local\ exit!
--8<---------------cut here---------------end--------------->8---

15 calls of file-truename (dired fontification), with 1 call of
tramp-sh-handle-file-truename each time. That sounds proper.

Tramp doesn't cache erroneous results, so it doesn't remember the
truename of "/ssh:gandalf:~/tmp/zzz". That's it, we can live with it I
guess.

Best regards, Michael.

bug#73046: 29.4; Emacs 100% CPU usage for several seconds when opening dired buffer over TRAMP

[Michael Albinus via Bug reports for GNU Emacs, the Swiss army knife of text editors]

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

Suhail Singh <suhailsingh247@gmail.com> writes:

Hi,

> The above observations seem consistent with Michael's comments above
> regd. font-lock checks for "Broken Symbolink link" and "Symbolic link to
> a directory".  As such, if Michael's proposal below is implemented I
> believe it would be an adequate fix to the issue:
>
>>>> I believe it would be helpful to suppress these checks via a user
>>>> option. And no, the checks shouldn't be suppressed for remote
>>>> directories in general, on a fast connection they are valuable.

I gave it a try, see appended patch. There's a new user option
`dired-highlight-symlinks'. If non-nil (the default), symlinks are
highlighted the same way as now. With a nil value, they aren't.

You can switch this option on and off globally. However, it would be
better to do this host-wise. For this, we have connection-local
variables. The following code snippet in your ".emacs" switches the
option off for the remote host "remotehost".

--8<---------------cut here---------------start------------->8---
(connection-local-set-profile-variables
 'my-dired-profile
 '((dired-highlight-symlinks . nil)))

(connection-local-set-profiles
 '(:application tramp :machine "remotehost")
 'my-dired-profile)
--8<---------------cut here---------------end--------------->8---

Comments?

Best regards, Michael.


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

diff --git a/lisp/dired.el b/lisp/dired.el
index 0d526dfc376..53d6d213951 100644
--- a/lisp/dired.el
+++ b/lisp/dired.el
@@ -738,6 +738,13 @@ dired-ignored-face
 \f
 ;;; Font-lock

+(defcustom dired-highlight-symlinks t
+  "Whether symlinks shall use an own face.
+Set it to nil for remote directories, which suffer from a slow connection."
+  :type 'boolean
+  :group 'dired
+  :version "31.1")
+
 (defvar dired-font-lock-keywords
   (list
    ;;
@@ -815,11 +822,13 @@ dired-font-lock-keywords
    ;; Broken Symbolic link.
    (list dired-re-sym
          (list (lambda (end)
-                 (let* ((file (dired-file-name-at-point))
-                        (truename (ignore-errors (file-truename file))))
-                   ;; either not existent target or circular link
-                   (and (not (and truename (file-exists-p truename)))
-                        (search-forward-regexp "\\(.+\\) \\(->\\) ?\\(.+\\)" end t))))
+                 (when (connection-local-value dired-highlight-symlinks)
+                   (let* ((file (dired-file-name-at-point))
+                          (truename (ignore-errors (file-truename file))))
+                     ;; either not existent target or circular link
+                     (and (not (and truename (file-exists-p truename)))
+                          (search-forward-regexp
+                           "\\(.+\\) \\(->\\) ?\\(.+\\)" end t)))))
                '(dired-move-to-filename)
                nil
                '(1 'dired-broken-symlink)
@@ -829,10 +838,12 @@ dired-font-lock-keywords
    ;; Symbolic link to a directory.
    (list dired-re-sym
          (list (lambda (end)
-                 (when-let* ((file (dired-file-name-at-point))
-                             (truename (ignore-errors (file-truename file))))
-                   (and (file-directory-p truename)
-		        (search-forward-regexp "\\(.+-> ?\\)\\(.+\\)" end t))))
+                 (when (connection-local-value dired-highlight-symlinks)
+                   (when-let* ((file (dired-file-name-at-point))
+                               (truename (ignore-errors (file-truename file))))
+                     (and (file-directory-p truename)
+		          (search-forward-regexp
+                           "\\(.+-> ?\\)\\(.+\\)" end t)))))
                '(dired-move-to-filename)
                nil
                '(1 dired-symlink-face)
@@ -841,12 +852,13 @@ dired-font-lock-keywords
    ;; Symbolic link to a non-directory.
    (list dired-re-sym
          (list (lambda (end)
-                 (when-let ((file (dired-file-name-at-point)))
-                   (let ((truename (ignore-errors (file-truename file))))
-                     (and (or (not truename)
-		              (not (file-directory-p truename)))
-		          (search-forward-regexp "\\(.+-> ?\\)\\(.+\\)"
-                                                 end t)))))
+                 (when (connection-local-value dired-highlight-symlinks)
+                   (when-let ((file (dired-file-name-at-point)))
+                     (let ((truename (ignore-errors (file-truename file))))
+                       (and (or (not truename)
+		                (not (file-directory-p truename)))
+		            (search-forward-regexp
+                             "\\(.+-> ?\\)\\(.+\\)" end t))))))
                '(dired-move-to-filename)
                nil
                '(1 dired-symlink-face)

bug#73046: 29.4; Emacs 100% CPU usage for several seconds when opening dired buffer over TRAMP

[Suhail Singh]

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

>>>>> I believe it would be helpful to suppress these checks via a user
>>>>> option. And no, the checks shouldn't be suppressed for remote
>>>>> directories in general, on a fast connection they are valuable.
>
> I gave it a try, see appended patch.

Thank you for sharing the patch.  I haven't tested the patch yet, so my
comments below are based on reviewing the code and my experience with
the workaround I currently have.

> There's a new user option `dired-highlight-symlinks'. If non-nil (the
> default), symlinks are highlighted the same way as now. With a nil
> value, they aren't.

I propose that the non-default behaviour be that `dired-symlink-face' is
applied to the entirety of the symlink.  If you agree, it might be
better to additionally rename `dired-highlight-symlinks' accordingly to
reflect the updated behaviour.

> You can switch this option on and off globally. However, it would be
> better to do this host-wise. For this, we have connection-local
> variables. The following code snippet in your ".emacs" switches the
> option off for the remote host "remotehost".
>
> (connection-local-set-profile-variables
>  'my-dired-profile
>  '((dired-highlight-symlinks . nil)))
>
> (connection-local-set-profiles
>  '(:application tramp :machine "remotehost")
>  'my-dired-profile)
>
> Comments?

TIL about connection-local variables.  Yes, this would be helpful.
However, if so desired, I imagine that setting
`dired-highlight-symlinks' buffer-locally in the `dired-mode-hook' would
work as well.  Is my understanding correct?

-- 
Suhail

bug#73046: 29.4; Emacs 100% CPU usage for several seconds when opening dired buffer over TRAMP

[Michael Albinus via Bug reports for GNU Emacs, the Swiss army knife of text editors]

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

Suhail Singh <suhailsingh247@gmail.com> writes:

Hi Suhail,

>> There's a new user option `dired-highlight-symlinks'. If non-nil (the
>> default), symlinks are highlighted the same way as now. With a nil
>> value, they aren't.
>
> I propose that the non-default behaviour be that `dired-symlink-face' is
> applied to the entirety of the symlink.  If you agree, it might be
> better to additionally rename `dired-highlight-symlinks' accordingly to
> reflect the updated behaviour.

Good catch, see reworked patch below. The user option has been renamed
to dired-check-symlinks.

> TIL about connection-local variables.  Yes, this would be helpful.
> However, if so desired, I imagine that setting
> `dired-highlight-symlinks' buffer-locally in the `dired-mode-hook' would
> work as well.  Is my understanding correct?

Yes, connection-local variables are implemented as buffer-local
variables.

Best regards, Michael.


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

diff --git a/lisp/dired.el b/lisp/dired.el
index 0d526dfc376..bc984c3506d 100644
--- a/lisp/dired.el
+++ b/lisp/dired.el
@@ -738,6 +738,13 @@ dired-ignored-face
 \f
 ;;; Font-lock

+(defcustom dired-check-symlinks t
+  "Whether symlinks are checked for validity.
+Set it to nil for remote directories, which suffer from a slow connection."
+  :type 'boolean
+  :group 'dired
+  :version "31.1")
+
 (defvar dired-font-lock-keywords
   (list
    ;;
@@ -815,11 +822,13 @@ dired-font-lock-keywords
    ;; Broken Symbolic link.
    (list dired-re-sym
          (list (lambda (end)
-                 (let* ((file (dired-file-name-at-point))
-                        (truename (ignore-errors (file-truename file))))
-                   ;; either not existent target or circular link
-                   (and (not (and truename (file-exists-p truename)))
-                        (search-forward-regexp "\\(.+\\) \\(->\\) ?\\(.+\\)" end t))))
+                 (when (connection-local-value dired-check-symlinks)
+                   (let* ((file (dired-file-name-at-point))
+                          (truename (ignore-errors (file-truename file))))
+                     ;; either not existent target or circular link
+                     (and (not (and truename (file-exists-p truename)))
+                          (search-forward-regexp
+                           "\\(.+\\) \\(->\\) ?\\(.+\\)" end t)))))
                '(dired-move-to-filename)
                nil
                '(1 'dired-broken-symlink)
@@ -829,10 +838,12 @@ dired-font-lock-keywords
    ;; Symbolic link to a directory.
    (list dired-re-sym
          (list (lambda (end)
-                 (when-let* ((file (dired-file-name-at-point))
-                             (truename (ignore-errors (file-truename file))))
-                   (and (file-directory-p truename)
-		        (search-forward-regexp "\\(.+-> ?\\)\\(.+\\)" end t))))
+                 (when (connection-local-value dired-check-symlinks)
+                   (when-let* ((file (dired-file-name-at-point))
+                               (truename (ignore-errors (file-truename file))))
+                     (and (file-directory-p truename)
+		          (search-forward-regexp
+                           "\\(.+-> ?\\)\\(.+\\)" end t)))))
                '(dired-move-to-filename)
                nil
                '(1 dired-symlink-face)
@@ -841,12 +852,15 @@ dired-font-lock-keywords
    ;; Symbolic link to a non-directory.
    (list dired-re-sym
          (list (lambda (end)
-                 (when-let ((file (dired-file-name-at-point)))
-                   (let ((truename (ignore-errors (file-truename file))))
-                     (and (or (not truename)
-		              (not (file-directory-p truename)))
-		          (search-forward-regexp "\\(.+-> ?\\)\\(.+\\)"
-                                                 end t)))))
+                 (if (not (connection-local-value dired-check-symlinks))
+                     (search-forward-regexp
+                      "\\(.+-> ?\\)\\(.+\\)" end t)
+                   (when-let ((file (dired-file-name-at-point)))
+                     (let ((truename (ignore-errors (file-truename file))))
+                       (and (or (not truename)
+		                (not (file-directory-p truename)))
+		            (search-forward-regexp
+                             "\\(.+-> ?\\)\\(.+\\)" end t))))))
                '(dired-move-to-filename)
                nil
                '(1 dired-symlink-face)

bug#73046: 29.4; Emacs 100% CPU usage for several seconds when opening dired buffer over TRAMP

[Suhail Singh]

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

>     ;; Symbolic link to a non-directory.
>     (list dired-re-sym
>           (list (lambda (end)
> -                 (when-let ((file (dired-file-name-at-point)))
> -                   (let ((truename (ignore-errors (file-truename file))))
> -                     (and (or (not truename)
> -		              (not (file-directory-p truename)))
> -		          (search-forward-regexp "\\(.+-> ?\\)\\(.+\\)"
> -                                                 end t)))))
> +                 (if (not (connection-local-value dired-check-symlinks))
> +                     (search-forward-regexp
> +                      "\\(.+-> ?\\)\\(.+\\)" end t)
> +                   (when-let ((file (dired-file-name-at-point)))
> +                     (let ((truename (ignore-errors (file-truename file))))
> +                       (and (or (not truename)
> +		                (not (file-directory-p truename)))
> +		            (search-forward-regexp
> +                             "\\(.+-> ?\\)\\(.+\\)" end t))))))

Minor nitpick: given the comment for this section (which seems to
suggest this only applies to symlinks to non-directories), wouldn't it
be "better" to simply have something like below instead for the if-then
case?  I.e., a separate entry in dired-font-lock-keywords for the
failsafe.

#+begin_src emacs-lisp
  ;; Generic face for symbolic links
  (list dired-re-sym
        (when (not (connection-local-value dired-check-symlinks))
          '(".+" (dired-move-to-filename) nil (0 dired-symlink-face))))
#+end_src

This is essentially what I have in my config today, and seems to behave
as expected.

-- 
Suhail

bug#73046: 29.4; Emacs 100% CPU usage for several seconds when opening dired buffer over TRAMP

[Michael Albinus via Bug reports for GNU Emacs, the Swiss army knife of text editors]

Suhail Singh <suhailsingh247@gmail.com> writes:

Hi Suhail,

>>     ;; Symbolic link to a non-directory.
>>     (list dired-re-sym
>>           (list (lambda (end)
>> -                 (when-let ((file (dired-file-name-at-point)))
>> -                   (let ((truename (ignore-errors (file-truename file))))
>> -                     (and (or (not truename)
>> -		              (not (file-directory-p truename)))
>> -		          (search-forward-regexp "\\(.+-> ?\\)\\(.+\\)"
>> -                                                 end t)))))
>> +                 (if (not (connection-local-value dired-check-symlinks))
>> +                     (search-forward-regexp
>> +                      "\\(.+-> ?\\)\\(.+\\)" end t)
>> +                   (when-let ((file (dired-file-name-at-point)))
>> +                     (let ((truename (ignore-errors (file-truename file))))
>> +                       (and (or (not truename)
>> +		                (not (file-directory-p truename)))
>> +		            (search-forward-regexp
>> +                             "\\(.+-> ?\\)\\(.+\\)" end t))))))
>
> Minor nitpick: given the comment for this section (which seems to
> suggest this only applies to symlinks to non-directories), wouldn't it
> be "better" to simply have something like below instead for the if-then
> case?  I.e., a separate entry in dired-font-lock-keywords for the
> failsafe.
>
> #+begin_src emacs-lisp
>   ;; Generic face for symbolic links
>   (list dired-re-sym
>         (when (not (connection-local-value dired-check-symlinks))
>           '(".+" (dired-move-to-filename) nil (0 dired-symlink-face))))
> #+end_src
>
> This is essentially what I have in my config today, and seems to behave
> as expected.

Possible, but I don't see that one version is "better" or "worse" than
the other. So I don't see a need to change it.

Best regards, Michael.

bug#73046: 29.4; Emacs 100% CPU usage for several seconds when opening dired buffer over TRAMP

[Suhail Singh]

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

>>>     ;; Symbolic link to a non-directory.
>>> ...
>>> +                             "\\(.+-> ?\\)\\(.+\\)" end t))))))
>>
>> Minor nitpick: given the comment for this section (which seems to
>> suggest this only applies to symlinks to non-directories), wouldn't it
>> be "better" to simply have something like below instead for the if-then
>> case?  I.e., a separate entry in dired-font-lock-keywords for the
>> failsafe.
>>
>> #+begin_src emacs-lisp
>>   ;; Generic face for symbolic links
>>   (list dired-re-sym
>>         (when (not (connection-local-value dired-check-symlinks))
>>           '(".+" (dired-move-to-filename) nil (0 dired-symlink-face))))
>> #+end_src
>>
>> This is essentially what I have in my config today, and seems to behave
>> as expected.
>
> Possible, but I don't see that one version is "better" or "worse" than
> the other.

Understood.

> So I don't see a need to change it.

The comment ";; Symbolic link to a non-directory." should probably be
updated in that case, right?  Apologies for the noise, in case I have
misunderstood the patch.

I should be able to test out the patch later this coming week.  In case
that would be helpful, please let me know.  Thank you for adding this.

-- 
Suhail

bug#73046: 29.4; Emacs 100% CPU usage for several seconds when opening dired buffer over TRAMP

[Michael Albinus via Bug reports for GNU Emacs, the Swiss army knife of text editors]

Suhail Singh <suhailsingh247@gmail.com> writes:

>> So I don't see a need to change it.
>
> The comment ";; Symbolic link to a non-directory." should probably be
> updated in that case, right?  Apologies for the noise, in case I have
> misunderstood the patch.

Sure. I changed it already in my master checkout, after you pointed me
to this.

> I should be able to test out the patch later this coming week.  In case
> that would be helpful, please let me know.  Thank you for adding this.

Yes, please do. I will also wait for Eli's OK, and then I will push it
to the master branch. Plus little bit of doc in the Emacs and Tramp
manuals.

Best regards, Michael.

bug#73046: 29.4; Emacs 100% CPU usage for several seconds when opening dired buffer over TRAMP

[Michael Albinus via Bug reports for GNU Emacs, the Swiss army knife of text editors]

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

Hi,

>> I should be able to test out the patch later this coming week.  In case
>> that would be helpful, please let me know.  Thank you for adding this.
>
> Yes, please do. I will also wait for Eli's OK, and then I will push it
> to the master branch. Plus little bit of doc in the Emacs and Tramp
> manuals.

Oops, I've been over-eager. Pushed already everything to master.

Pls send further comments, if any. Otherwise, I'll close the bug in a
couple of days.

Best regards, Michael.

bug#73046: 29.4; Emacs 100% CPU usage for several seconds when opening dired buffer over TRAMP

[Suhail Singh]

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

>>> > FWIW, I cannot reproduce this: I tried Dired on a remote host with
>>> > which I have connection that is quite slow, and saw neither high CPU
>>> > usage nor a significant delay in displaying a Dired buffer.
>>>
>>> It seems to be related to font-locking, indeed. See variable
>>> `dired-font-lock-keywords'. It specifies face recognition running basic
>>> file oprtations. For example, ";; Broken Symbolic link" calls
>>> `file-truename' and `file-exists-p', while "Symbolic link to a directory"
>>> and ";; Symbolic link to a non-directory" invoke `file-truename' and
>>> `file-directory-p'.
>>
>> But font-lock is ON by default, so what I saw also includes this,
>> right?
>
> Sure. But we don't know the exact setting of the OP. The connection
> could be extremely slow for him, Tramp's cache might be disabled,
> whatever. Perhaps it's worth to rerun the test with "emacs -Q".

The issue was observed with emacs -Q on a remote directory that had 22
symlinks.  On the affected host, I am able to reliably reproduce the
issue by evaluating the code below and then navigating to
/tmp/test/links in dired via TRAMP.

#+name: perf-fix/tramp/font-lock-on-dired/reproducer
#+begin_src sh
  cd /tmp
  rm -rf /tmp/test
  mkdir /tmp/test
  cd /tmp/test
  for i in `seq -w 0 21`; do
      mkdir -p src/"$i"
  done
  mkdir -p links
  cd links
  for i in `seq -w 0 21`; do
      ln -sf /tmp/test/src/"$i"
  done
#+end_src

Notably, for the affected host, the issue is reproducible using above
even after a new OS install.  However, the above test case doesn't cover
all variables affecting the issue.  Specifically, when I run the above
code on a different host (with faster connection and fewer hops to get
to) and navigate to /tmp/test/links the severity of the issue is much
less.  That being said, the profiler reports (starting from emacs -Q and
after establishing connection with host in question via TRAMP) for both
the affected and not-as-affected host are similar.  I believe the issue
is present on the unaffected host as well, but with much less severity
for some reason.

My guess is that connection speed (in addition to the number of symlinks
in the directory in question) is a determining factor.  I am speculating
here, but perhaps TRAMP is busy-waiting for a response?  That would be
consistent with what I observe, but I am not sure how to verify that.

>>> I believe it would be helpful to suppress these checks via a user
>>> option.
>>
>> What's wrong with "M-x font-lock-mode RET"?
>
> You would deactivate all fontifications, not only the ones related to
> symlinks.
>
> And you must do this in a hook of the dired buffer, before fontification
> happens.

Yes, precisely.  That is my current workaround.  It's far from ideal,
but it at least allows Emacs to be in a semi-workable state.  It would
be much better if there were a way to suppress only the "expensive"
font-locking checks in this case.

> There exist `dired-hide-details-mode', which I don't know. Perhaps
> enabling it in time would do the job?

It, unfortunately, doesn't help.

-- 
Suhail

bug#73046: 29.4; Emacs 100% CPU usage for several seconds when opening dired buffer over TRAMP

[Suhail Singh]

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

>>> Based on =profiler-report=, the following function "chains" consume most of the
>>> CPU:
>>> - `font-lock-fontify-keywords-region'
>>>   - tramp-sh-file-name-handler
>>>     - tramp-sh-handle-file-truename
>>>       - `tramp-wait-for-regexp'
>>>     - tramp-sh-handle-file-exists-p
>>>       - `tramp-wait-for-regexp'
>>>     - tramp-sh-handle-file-directory-p
>>>       - `tramp-wait-for-regexp'
>>>     - tramp-sh-handle-file-attributes
>>>       - `tramp-wait-for-regexp'
>>>
>>> As noted previously, disabling global-font-lock-mode helps.
>>
>> FWIW, I cannot reproduce this: I tried Dired on a remote host with
>> which I have connection that is quite slow, and saw neither high CPU
>> usage nor a significant delay in displaying a Dired buffer.
>
> It seems to be related to font-locking, indeed. See variable
> `dired-font-lock-keywords'. It specifies face recognition running basic
> file oprtations. For example, ";; Broken Symbolic link" calls
> `file-truename' and `file-exists-p', while "Symbolic link to a directory"
> and ";; Symbolic link to a non-directory" invoke `file-truename' and
> `file-directory-p'.
>
> I believe it would be helpful to suppress these checks via a user
> option.

I agree.  Having a user configuration(s) that allows one to selectively
disable some of the possibly more expensive checks would be valuable.
If that were available, user configuration code could determine their
own rules or thresholds as to when those options should be toggled
(without disabling font-locking in its entirety).

If performance degradation could be dynamically checked by Emacs
(something akin to so-long-action and so-long-predicate, but for this
instance of font-locking instead) that would be ideal, but it may not be
easy to implement and it certainly isn't necessary - when things get
unresponsive, it's pretty apparent.

> And no, the checks shouldn't be suppressed for remote directories in
> general, on a fast connection they are valuable.

I agree.

> In bug#17064, the impact of these calls where discussed. The conclusion was
>
>> Or could this have any bad side effects?  Is it maybe too heavy to call
>> `file-truename'?
>
> Normally, there aren't many symlinks in a buffer, so I think the
> performance impact would be negligible.
>
> Likely, this was too optimistic ...

For the host where I noticed this issue, the directory in question had
22 symlinks.

-- 
Suhail

bug#73046: 29.4; Emacs 100% CPU usage for several seconds when opening dired buffer over TRAMP

[Suhail Singh]

Eli Zaretskii <eliz@gnu.org> writes:

>> The version of `ls' on this host is:
>> 
>> #+begin_quote
>>   ls (GNU coreutils) 8.32
>>   Copyright (C) 2020 Free Software Foundation, Inc.
>>   License GPLv3+: GNU GPL version 3 or later <https://gnu.org/licenses/gpl.html>.
>>   This is free software: you are free to change and redistribute it.
>>   There is NO WARRANTY, to the extent permitted by law.
>> 
>>   Written by Richard M. Stallman and David MacKenzie.
>> #+end_quote
>
> This cannot be true: the --dired option was added to 'ls' way earlier.
> I have Coreutils 6.9 from 2007 on one of my systems, and --dired is
> supported there.  To see if it is supported, try this:
>
>   $ ls -al --dired
>
> You should see 2 extra lines of output after the listing, each one
> starting with "//DIRED".

I understand that said version should have had --dired support, but
that's not what I observed.  Regardless, I got the sysadmin to do an
upgrade and now `ls --dired' is giving the expected output.  However,
the performance issues still persist and continue to be reproducible on
my end via emacs -Q.

-- 
Suhail

bug#73046: 29.4; Emacs 100% CPU usage for several seconds when opening dired buffer over TRAMP

[Suhail Singh]

Eli Zaretskii <eliz@gnu.org> writes:

>> Based on =profiler-report=, the following function "chains" consume most of the
>> CPU:
>> - `font-lock-fontify-keywords-region'
>>   - tramp-sh-file-name-handler
>>     - tramp-sh-handle-file-truename
>>       - `tramp-wait-for-regexp'
>>     - tramp-sh-handle-file-exists-p
>>       - `tramp-wait-for-regexp'
>>     - tramp-sh-handle-file-directory-p
>>       - `tramp-wait-for-regexp'
>>     - tramp-sh-handle-file-attributes
>>       - `tramp-wait-for-regexp'
>> 
>> As noted previously, disabling global-font-lock-mode helps.
>
> FWIW, I cannot reproduce this: I tried Dired on a remote host with
> which I have connection that is quite slow, and saw neither high CPU
> usage nor a significant delay in displaying a Dired buffer.

In my case, the directory in question had 22 symlinks.  How many
symlinks did you try with?

-- 
Suhail

bug#73046: 29.4; Emacs 100% CPU usage for several seconds when opening dired buffer over TRAMP

[Michael Albinus via Bug reports for GNU Emacs, the Swiss army knife of text editors]

Jake Nelson <jake.nelson@rutgers.edu> writes:

Hi Jake,

> I had to revert 652a8a0838b38a6eab85c55fc61cedd1c61ef20f
>
> I could load a remote file with via tramp, but attempting to edit the
> file spiked to 100% cpu usage and I had to C-g to recover.

Could you, pls, reenable 652a8a0838b38a6eab85c55fc61cedd1c61ef20f
temporarily? Then recompile Emacs, and run

--8<---------------cut here---------------start------------->8---
# emacs -Q -l tramp --eval '(setq tramp-verbose 10)' /ssh:some-host:/etc/somedir/file.yaml
--8<---------------cut here---------------end--------------->8---

Try to edit the file. When the problem appears, return control by
C-g. Show the resulting *debug tramp/ssh some-host* buffer. Likely, it
is large; you could send it to me directly.

> Thanks,
> Jake

Best regards, Michael.

bug#73046: 29.4; Emacs 100% CPU usage for several seconds when opening dired buffer over TRAMP

[Michael Albinus via Bug reports for GNU Emacs, the Swiss army knife of text editors]

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

Hi Jake,

>> I had to revert 652a8a0838b38a6eab85c55fc61cedd1c61ef20f
>>
>> I could load a remote file with via tramp, but attempting to edit the
>> file spiked to 100% cpu usage and I had to C-g to recover.
>
> Could you, pls, reenable 652a8a0838b38a6eab85c55fc61cedd1c61ef20f
> temporarily? Then recompile Emacs, and run
>
> # emacs -Q -l tramp --eval '(setq tramp-verbose 10)' /ssh:some-host:/etc/somedir/file.yaml
>
> Try to edit the file. When the problem appears, return control by
> C-g. Show the resulting *debug tramp/ssh some-host* buffer. Likely, it
> is large; you could send it to me directly.

Ping. Could you, pls, provide the needed information? Otherwise, we
cannot do anything for you.

>> Thanks,
>> Jake

Best regards, Michael.

bug#73046: 29.4; Emacs 100% CPU usage for several seconds when opening dired buffer over TRAMP

[Jake Nelson via Bug reports for GNU Emacs, the Swiss army knife of text editors]

I ran emacs -Q and the issue did not occur.  Apologies for not checking
with -Q that prior to reporting the issue.

Thank you,
Jake

On Fri, Sep 20 2024, Michael Albinus <michael.albinus@gmx.de> wrote:

> Michael Albinus <michael.albinus@gmx.de> writes:
>
> Hi Jake,
>
>>> I had to revert 652a8a0838b38a6eab85c55fc61cedd1c61ef20f
>>>
>>> I could load a remote file with via tramp, but attempting to edit the
>>> file spiked to 100% cpu usage and I had to C-g to recover.
>>
>> Could you, pls, reenable 652a8a0838b38a6eab85c55fc61cedd1c61ef20f
>> temporarily? Then recompile Emacs, and run
>>
>> # emacs -Q -l tramp --eval '(setq tramp-verbose 10)' /ssh:some-host:/etc/somedir/file.yaml
>>
>> Try to edit the file. When the problem appears, return control by
>> C-g. Show the resulting *debug tramp/ssh some-host* buffer. Likely, it
>> is large; you could send it to me directly.
>
> Ping. Could you, pls, provide the needed information? Otherwise, we
> cannot do anything for you.
>
>>> Thanks,
>>> Jake
>
> Best regards, Michael.

bug#73046: 29.4; Emacs 100% CPU usage for several seconds when opening dired buffer over TRAMP

[Michael Albinus via Bug reports for GNU Emacs, the Swiss army knife of text editors]

Jake Nelson <jake.nelson@rutgers.edu> writes:

> I ran emacs -Q and the issue did not occur.  Apologies for not checking
> with -Q that prior to reporting the issue.

Thanks for the feedback!

> Thank you,
> Jake

Best regards, Michael.