如何查找历史线程阻塞原因_使用strace查找Emacs启动阻塞的原因|Linux中国

之前就觉得我的 Emacs 启动好慢&＃xff0c;查看启动日志会发现启动到一般的时候会有一个比较长时间的卡顿。之前一直没有理会它&＃xff0c;今天花了点时间探索了一下&＃xff0c;发现罪魁祸首居然是 exec-path-from-shell 这个包。

现将探索的过程记录如下&＃xff1a;由于使用了 spacemacs 的配置&＃xff0c;配置上比较复杂&＃xff0c;不太想通过实验缩减配置的方式来摸索出问题的地方。刚好最近在学习使用 strace 工具&＃xff0c;因此决定使用 strace 来看看 Emacs 到底卡在哪里。

strace emacs --fg-daemon

输出的内容特别多&＃xff0c;这里只截取卡顿前的部分内容

readlinkat(AT_FDCWD, "/home", 0x7ffd1d3abb50, 1024) &＃61; -1 EINVAL (无效的参数)readlinkat(AT_FDCWD, "/home/lujun9972", 0x7ffd1d3abf00, 1024) &＃61; -1 EINVAL (无效的参数)readlinkat(AT_FDCWD, "/home/lujun9972/.emacs.d", 0x7ffd1d3ac2b0, 1024) &＃61; -1 EINVAL (无效的参数)readlinkat(AT_FDCWD, "/home/lujun9972/.emacs.d/elpa", 0x7ffd1d3ac660, 1024) &＃61; -1 EINVAL (无效的参数)readlinkat(AT_FDCWD, "/home/lujun9972/.emacs.d/elpa/exec-path-from-shell-20180323.1904", 0x7ffd1d3aca10, 1024) &＃61; -1 EINVAL (无效的参数)readlinkat(AT_FDCWD, "/home/lujun9972/.emacs.d/elpa/exec-path-from-shell-20180323.1904/exec-path-from-shell.elc", 0x7ffd1d3acdc0, 1024) &＃61; -1 EINVAL (无效的参数)lseek(7, -2655, SEEK_CUR) &＃61; 1441read(7, "\n(defvar exec-path-from-shell-de"..., 4096) &＃61; 4096lseek(7, 5537, SEEK_SET) &＃61; 5537lseek(7, 5537, SEEK_SET) &＃61; 5537lseek(7, 5537, SEEK_SET) &＃61; 5537lseek(7, 5537, SEEK_SET) &＃61; 5537lseek(7, 5537, SEEK_SET) &＃61; 5537lseek(7, 5537, SEEK_SET) &＃61; 5537brk(0x7507000) &＃61; 0x7507000lseek(7, 5537, SEEK_SET) &＃61; 5537lseek(7, 5537, SEEK_SET) &＃61; 5537lseek(7, 5537, SEEK_SET) &＃61; 5537read(7, "230\\205\26\0\t\22\\307\\310\t!\vC\\\"\\211\24\\2"..., 4096) &＃61; 2430lseek(7, 7967, SEEK_SET) &＃61; 7967lseek(7, 7967, SEEK_SET) &＃61; 7967lseek(7, 7967, SEEK_SET) &＃61; 7967lseek(7, 7967, SEEK_SET) &＃61; 7967read(7, "", 4096) &＃61; 0close(7) &＃61; 0getpid() &＃61; 10818faccessat(AT_FDCWD, "/home/lujun9972/bin/printf", X_OK) &＃61; -1 ENOENT (没有那个文件或目录)faccessat(AT_FDCWD, "/usr/local/sbin/printf", X_OK) &＃61; -1 ENOENT (没有那个文件或目录)faccessat(AT_FDCWD, "/usr/local/bin/printf", X_OK) &＃61; -1 ENOENT (没有那个文件或目录)faccessat(AT_FDCWD, "/usr/bin/printf", X_OK) &＃61; 0stat("/usr/bin/printf", {st_mode&＃61;S_IFREG|0755, st_size&＃61;51176, ...}) &＃61; 0openat(AT_FDCWD, "/dev/null", O_RDONLY|O_CLOEXEC) &＃61; 7faccessat(AT_FDCWD, "/proc/5070/fd/.", F_OK) &＃61; 0faccessat(AT_FDCWD, "/proc/5070/fd/.", F_OK) &＃61; 0faccessat(AT_FDCWD, "/bin/bash", X_OK) &＃61; 0stat("/bin/bash", {st_mode&＃61;S_IFREG|0755, st_size&＃61;903440, ...}) &＃61; 0pipe2([8, 9], O_CLOEXEC) &＃61; 0rt_sigprocmask(SIG_BLOCK, [INT CHLD], [], 8) &＃61; 0vfork() &＃61; 10949rt_sigprocmask(SIG_SETMASK, [], NULL, 8) &＃61; 0close(9) &＃61; 0close(7) &＃61; 0read(8, "bash: \346\227\240\346\263\225\350\256\276\345\256\232\347\273\210\347\253\257\350\277\233\347\250\213\347\273"..., 16384) &＃61; 74read(8, "bash: \346\255\244 shell \344\270\255\346\227\240\344\273\273\345\212\241\346\216\247\345"..., 16310) &＃61; 35read(8, "setterm: \347\273\210\347\253\257 xterm-256color \344"..., 16275) &＃61; 51read(8, "Couldn&＃39;t get a file descriptor r"..., 16224) &＃61; 56read(8, "bash: [: \357\274\232\351\234\200\350\246\201\346\225\264\346\225\260\350\241\250\350\276\276\345\274"..., 16168) &＃61; 34read(8, "Your display number is 0\n", 16134) &＃61; 25read(8, "Test whether fcitx is running co"..., 16109) &＃61; 53read(8, "Fcitx is running correctly.\n\n&＃61;&＃61;&＃61;"..., 16056) &＃61; 87read(8, "Launch fbterm...\n", 15969) &＃61; 17read(8, "stdin isn&＃39;t a tty!\n", 15952) &＃61; 19read(8, "__RESULT\0/home/lujun9972/bin:/ho"..., 15933) &＃61; 298read(8, 0x7ffd1d39ce9d, 15635) &＃61; ? ERESTARTSYS (To be restarted if SA_RESTART is set)--- SIGCHLD {si_signo&＃61;SIGCHLD, si_code&＃61;CLD_EXITED, si_pid&＃61;10949, si_uid&＃61;1000, si_status&＃61;0, si_utime&＃61;10, si_stime&＃61;7} ---rt_sigreturn({mask&＃61;[]}) &＃61; -1 EINTR (被中断的系统调用)read(8, "", 15635) &＃61; 0wait4(10949, [{WIFEXITED(s) && WEXITSTATUS(s) &＃61;&＃61; 0}], 0, NULL) &＃61; 10949close(8) &＃61; 0getpid() &＃61; 10818faccessat(AT_FDCWD, "/home/lujun9972/bin/printf", X_OK) &＃61; -1 ENOENT (没有那个文件或目录)faccessat(AT_FDCWD, "/usr/local/sbin/printf", X_OK) &＃61; -1 ENOENT (没有那个文件或目录)faccessat(AT_FDCWD, "/usr/local/bin/printf", X_OK) &＃61; -1 ENOENT (没有那个文件或目录)faccessat(AT_FDCWD, "/usr/bin/printf", X_OK) &＃61; 0stat("/usr/bin/printf", {st_mode&＃61;S_IFREG|0755, st_size&＃61;51176, ...}) &＃61; 0openat(AT_FDCWD, "/dev/null", O_RDONLY|O_CLOEXEC) &＃61; 7faccessat(AT_FDCWD, "/proc/5070/fd/.", F_OK) &＃61; 0faccessat(AT_FDCWD, "/proc/5070/fd/.", F_OK) &＃61; 0faccessat(AT_FDCWD, "/bin/bash", X_OK) &＃61; 0stat("/bin/bash", {st_mode&＃61;S_IFREG|0755, st_size&＃61;903440, ...}) &＃61; 0pipe2([8, 9], O_CLOEXEC) &＃61; 0rt_sigprocmask(SIG_BLOCK, [INT CHLD], [], 8) &＃61; 0vfork() &＃61; 11679rt_sigprocmask(SIG_SETMASK, [], NULL, 8) &＃61; 0close(9) &＃61; 0close(7) &＃61; 0read(8, "setterm: \347\273\210\347\253\257 xterm-256color \344"..., 16384) &＃61; 51read(8, "Couldn&＃39;t get a file descriptor r"..., 16333) &＃61; 56read(8, "/home/lujun9972/.bash_profile: \347"..., 16277) &＃61; 72read(8, "Your display number is 0\nTest wh"..., 16205) &＃61; 78read(8, "Fcitx is running correctly.\n\n&＃61;&＃61;&＃61;"..., 16127) &＃61; 104read(8, "stdin isn&＃39;t a tty!\n", 16023) &＃61; 19read(8, "__RESULT\0b269cd09e7ec4e8a115188c"..., 16004) &＃61; 298read(8, 0x7ffd1d39cba6, 15706) &＃61; ? ERESTARTSYS (To be restarted if SA_RESTART is set)--- SIGCHLD {si_signo&＃61;SIGCHLD, si_code&＃61;CLD_EXITED, si_pid&＃61;11679, si_uid&＃61;1000, si_status&＃61;0, si_utime&＃61;1, si_stime&＃61;1} ---rt_sigreturn({mask&＃61;[]}) &＃61; -1 EINTR (被中断的系统调用)read(8,

很容易就可以看出&＃xff0c;当 Emacs 卡顿时&＃xff0c;它在尝试从 8 号文件句柄中读取内容。

那么 8 号文件句柄在哪里定义的呢&＃xff1f;往前看可以看到&＃xff1a;

pipe2([8, 9], O_CLOEXEC) &＃61; 0rt_sigprocmask(SIG_BLOCK, [INT CHLD], [], 8) &＃61; 0vfork() &＃61; 11679rt_sigprocmask(SIG_SETMASK, [], NULL, 8) &＃61; 0close(9) &＃61; 0

可以推测出&＃xff0c;Emacs 主进程 fork 出一个子进程(进程号为 11679)&＃xff0c;并通过管道读取子进程的内容。

然而&＃xff0c;从

--- SIGCHLD {si_signo&＃61;SIGCHLD, si_code&＃61;CLD_EXITED, si_pid&＃61;11679, si_uid&＃61;1000, si_status&＃61;0, si_utime&＃61;1, si_stime&＃61;1} ---rt_sigreturn({mask&＃61;[]}) &＃61; -1 EINTR (被中断的系统调用)read(8,

可以看出&＃xff0c;实际上子进程已经退出了(父进程收到 SIGCHLD 信号)&＃xff0c;父进程确依然在尝试从管道中读取内容&＃xff0c;导致的阻塞。

而且从

read(8, "setterm: \347\273\210\347\253\257 xterm-256color \344"..., 16384) &＃61; 51read(8, "Couldn&＃39;t get a file descriptor r"..., 16333) &＃61; 56read(8, "/home/lujun9972/.bash_profile: \347"..., 16277) &＃61; 72read(8, "Your display number is 0\nTest wh"..., 16205) &＃61; 78read(8, "Fcitx is running correctly.\n\n&＃61;&＃61;&＃61;"..., 16127) &＃61; 104read(8, "stdin isn&＃39;t a tty!\n", 16023) &＃61; 19read(8, "__RESULT\0b269cd09e7ec4e8a115188c"..., 16004) &＃61; 298read(8, 0x7ffd1d39cba6, 15706) &＃61; ? ERESTARTSYS (To be restarted if SA_RESTART is set)

看到&＃xff0c;子进程的输出似乎是我的交互式登录 bash 启动时的输出(加载了 .bash_profile)

在往前翻发现这么一段信息&＃xff1a;

readlinkat(AT_FDCWD, "/home", 0x7ffd1d3abb50, 1024) &＃61; -1 EINVAL (无效的参数)readlinkat(AT_FDCWD, "/home/lujun9972", 0x7ffd1d3abf00, 1024) &＃61; -1 EINVAL (无效的参数)readlinkat(AT_FDCWD, "/home/lujun9972/.emacs.d", 0x7ffd1d3ac2b0, 1024) &＃61; -1 EINVAL (无效的参数)readlinkat(AT_FDCWD, "/home/lujun9972/.emacs.d/elpa", 0x7ffd1d3ac660, 1024) &＃61; -1 EINVAL (无效的参数)readlinkat(AT_FDCWD, "/home/lujun9972/.emacs.d/elpa/exec-path-from-shell-20180323.1904", 0x7ffd1d3aca10, 1024) &＃61; -1 EINVAL (无效的参数)readlinkat(AT_FDCWD, "/home/lujun9972/.emacs.d/elpa/exec-path-from-shell-20180323.1904/exec-path-from-shell.elc", 0x7ffd1d3acdc0, 1024) &＃61; -1 EINVAL (无效的参数)lseek(7, -2655, SEEK_CUR) &＃61; 1441read(7, "\n(defvar exec-path-from-shell-de"..., 4096) &＃61; 4096

这很明显是跟 exec-path-from-shell 有关啊。

通过查看 exec-path-from-shell 的实现&＃xff0c;发现 exec-path-from-shell 的实现原理是通过实际调启一个 shell&＃xff0c;然后输出 PATH 和 MANPATH 的值的。而且对于 bash 来说&＃xff0c;默认的启动参数为 -i -l(可以通过exec-path-from-shell-arguments来设置)。也就是说 bash 会作为交互式的登录shell来启动的&＃xff0c;因此会加载 .bash_profile 和 .bashrc。

既然发现跟 exec-path-from-shell 这个包有关&＃xff0c;而且据说这个包对 Linux 其实意义不大&＃xff0c;那不如直接禁用掉好了。

dotspacemacs-excluded-packages &＃39;(exec-path-from-shell)

再次重启Emacs&＃xff0c;发现这次启动速度明显快了许多了。