Jiacai Liu's personal website

How to troubleshoot why tramp hang your Emacs

  tags: tramp emacs

When I was playing with my Emacs configs today, a tramp related message suddenly appeared in minibuffer:

Tramp: Opening connection nil for dev using ssh...

My Emacs also hang at the same moment since the dev host is out of reach. I haven’t used tramp for sometime, so when I first saw this message, I was curious about which function trigger tramp.

I have some experience in troubleshooting tramp hang issue before, and I know that some seemingly unrelated functions will access the opened tramp buffer, such as: file-truename, but I have no opened tramp buffer at this time, so why tramp got triggered?

In order to troubleshoot this:

  1. First we need to increase the tramp log level with (setq tramp-verbose 10)
  2. Then repeat the operation which trigger tramp.
  3. When Emacs got hung again, use C-g to try gain control back.

In my case, after hit C-g multiple times, my Emacs go alive, and there is a *debug tramp/ssh dev* buffer showing the backtrace of what happened:

20:23:33.548536 tramp-recentf-cleanup (10) #
  backtrace()
  tramp-error((tramp-file-name "ssh" nil nil "dev" nil "~/" nil) wrong-type-argument "listp abbreviate-file-name")
  tramp-signal-hook-function(wrong-type-argument (listp abbreviate-file-name))
  recentf-apply-filename-handlers("~/.config/emacs/deps.el")
  recentf-expand-file-name("~/.config/emacs/deps.el")
  recentf-cleanup()
  tramp-recentf-cleanup((tramp-file-name "ssh" nil nil "dev" nil "~/" nil))
  run-hook-with-args(tramp-recentf-cleanup (tramp-file-name "ssh" nil nil "dev" nil "~/" nil))
  tramp-cleanup-connection((tramp-file-name "ssh" nil nil "dev" nil "~/" nil) t)
  tramp-maybe-open-connection((tramp-file-name "ssh" nil nil "dev" nil "~/" nil))
  tramp-send-command((tramp-file-name "ssh" nil nil "dev" nil "~/" nil) "echo ~ 2>/dev/null; echo tramp_exit_status $?")
  tramp-send-command-and-check((tramp-file-name "ssh" nil nil "dev" nil "~/" nil) "echo ~")
  tramp-sh-handle-get-home-directory((tramp-file-name "ssh" nil nil "dev" nil "~/" nil) "")
  apply(tramp-sh-handle-get-home-directory ((tramp-file-name "ssh" nil nil "dev" nil "~/" nil) ""))
  tramp-sh-file-name-handler(tramp-get-home-directory (tramp-file-name "ssh" nil nil "dev" nil "~/" nil) "")
  apply(tramp-sh-file-name-handler tramp-get-home-directory ((tramp-file-name "ssh" nil nil "dev" nil "~/" nil) ""))
  tramp-file-name-handler(tramp-get-home-directory (tramp-file-name "ssh" nil nil "dev" nil "~/" nil) "")
  tramp-get-home-directory((tramp-file-name "ssh" nil nil "dev" nil "~/" nil) "")
  tramp-sh-handle-expand-file-name("/ssh:dev:~/" nil)
  apply(tramp-sh-handle-expand-file-name ("/ssh:dev:~/" nil))
  tramp-sh-file-name-handler(expand-file-name "/ssh:dev:~/" nil)
  apply(tramp-sh-file-name-handler expand-file-name ("/ssh:dev:~/" nil))
  tramp-file-name-handler(expand-file-name "/ssh:dev:~/" nil)
  expand-file-name("/ssh:dev:~/")
  read-file-name-default("Use file /dev/null: " "/dev/" "/dev/null" t "null" nil)
  read-file-name("Use file /dev/null: " "/dev/" "/dev/null" t "null")
  diff-find-file-name()
  diff-add-log-current-defuns()
  log-edit-generate-changelog-from-diff()
  funcall-interactively(log-edit-generate-changelog-from-diff)
  call-interactively(log-edit-generate-changelog-from-diff nil nil)
  command-execute(log-edit-generate-changelog-from-diff)

As you can see, log-edit-generate-changelog-from-diff is the function I actively called, which indirectly triggers tramp, and the key two lines of logs are:

  expand-file-name("/ssh:dev:~/")
  read-file-name-default("Use file /dev/null: " "/dev/" "/dev/null" t "null" nil)

expand-file-name's input is a remote file address, how did this come about? After all I was working on a entirely local project.

Digging down further inside read-file-name-default, this line invoke expand-file-name:

 (abbreviate-file-name "/dev/")

That is to say, /dev/ is the abbreviation of /ssh:dev:~/.

When troubleshooting here, in fact, you can continue to look abbreviate-file-name's the source code, but at this time I have a vague impression of this ssh address in my mind.

dev is a Linux machine that I often use in my daily development, and for convenience, I define such an abbreviation:

(setq directory-abbrev-alist '(("^/dev" . "/ssh:dev:~")))

In this way, I can directly open the files on dev by typing /dev when invoke find-file.

So the problem here is basically clear, abbreviate-file-name internally use directory-abbrev-alist look up abbreviation defined by user, this lookup unfortunately cause a tramp connection since it find a remote file.

After remove this abbreviation rule, the issue went away. Happy ending!

I hope my experience can help readers understand how to troubleshoot their tramp-related problems.

PS: As for why log-edit-generate-changelog-from-diff open /dev/ file, this is another question. Interested readers can continue to troubleshoot based on backtrace above.