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" <bug-gnu-emacs@gnu.org>]

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.