您的位置:首页 > 运维架构 > Linux

使用 strace 查找 Emacs 启动阻塞的原因 | Linux 中国

2019-09-29 13:14 1236 查看
刚好最近在学习使用 strace 工具,因此决定使用 strace 来看看 Emacs 到底卡在哪里。
-- Darksun

作者:Darksun

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

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

strace emacs --fg-daemon

输出的内容特别多,这里只截取卡顿前的部分内容

  1. readlinkat(AT_FDCWD, "/home", 0x7ffd1d3abb50, 1024) = -1 EINVAL (无效的参数)
  2. readlinkat(AT_FDCWD, "/home/lujun9972", 0x7ffd1d3abf00, 1024) = -1 EINVAL (无效的参数)
  3. readlinkat(AT_FDCWD, "/home/lujun9972/.emacs.d", 0x7ffd1d3ac2b0, 1024) = -1 EINVAL (无效的参数)
  4. readlinkat(AT_FDCWD, "/home/lujun9972/.emacs.d/elpa", 0x7ffd1d3ac660, 1024) = -1 EINVAL (无效的参数)
  5. readlinkat(AT_FDCWD, "/home/lujun9972/.emacs.d/elpa/exec-path-from-shell-20180323.1904", 0x7ffd1d3aca10, 1024) = -1 EINVAL (无效的参数)
  6. readlinkat(AT_FDCWD, "/home/lujun9972/.emacs.d/elpa/exec-path-from-shell-20180323.1904/exec-path-from-shell.elc", 0x7ffd1d3acdc0, 1024) = -1 EINVAL (无效的参数)
  7. lseek(7, -2655, SEEK_CUR) = 1441
  8. read(7, "\n(defvar exec-path-from-shell-de"..., 4096) = 4096
  9. lseek(7, 5537, SEEK_SET) = 5537
  10. lseek(7, 5537, SEEK_SET) = 5537
  11. lseek(7, 5537, SEEK_SET) = 5537
  12. lseek(7, 5537, SEEK_SET) = 5537
  13. lseek(7, 5537, SEEK_SET) = 5537
  14. lseek(7, 5537, SEEK_SET) = 5537
  15. brk(0x7507000) = 0x7507000
  16. lseek(7, 5537, SEEK_SET) = 5537
  17. lseek(7, 5537, SEEK_SET) = 5537
  18. lseek(7, 5537, SEEK_SET) = 5537
  19. read(7, "230\\205\26\0\t\22\\307\\310\t!\vC\\\"\\211\24\\2"..., 4096) = 2430
  20. lseek(7, 7967, SEEK_SET) = 7967
  21. lseek(7, 7967, SEEK_SET) = 7967
  22. lseek(7, 7967, SEEK_SET) = 7967
  23. lseek(7, 7967, SEEK_SET) = 7967
  24. read(7, "", 4096) = 0
  25. close(7) = 0
  26. getpid() = 10818
  27. faccessat(AT_FDCWD, "/home/lujun9972/bin/printf", X_OK) = -1 ENOENT (没有那个文件或目录)
  28. faccessat(AT_FDCWD, "/usr/local/sbin/printf", X_OK) = -1 ENOENT (没有那个文件或目录)
  29. faccessat(AT_FDCWD, "/usr/local/bin/printf", X_OK) = -1 ENOENT (没有那个文件或目录)
  30. faccessat(AT_FDCWD, "/usr/bin/printf", X_OK) = 0
  31. stat("/usr/bin/printf", {st_mode=S_IFREG|0755, st_size=51176, ...}) = 0
  32. openat(AT_FDCWD, "/dev/null", O_RDONLY|O_CLOEXEC) = 7
  33. faccessat(AT_FDCWD, "/proc/5070/fd/.", F_OK) = 0
  34. faccessat(AT_FDCWD, "/proc/5070/fd/.", F_OK) = 0
  35. faccessat(AT_FDCWD, "/bin/bash", X_OK) = 0
  36. stat("/bin/bash", {st_mode=S_IFREG|0755, st_size=903440, ...}) = 0
  37. pipe2([8, 9], O_CLOEXEC) = 0
  38. rt_sigprocmask(SIG_BLOCK, [INT CHLD], [], 8) = 0
  39. vfork() = 10949
  40. rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
  41. close(9) = 0
  42. close(7) = 0
  43. read(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) = 74
  44. read(8, "bash: \346\255\244 shell \344\270\255\346\227\240\344\273\273\345\212\241\346\216\247\345"..., 16310) = 35
  45. read(8, "setterm: \347\273\210\347\253\257 xterm-256color \344"..., 16275) = 51
  46. read(8, "Couldn't get a file descriptor r"..., 16224) = 56
  47. read(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) = 34
  48. read(8, "Your display number is 0\n", 16134) = 25
  49. read(8, "Test whether fcitx is running co"..., 16109) = 53
  50. read(8, "Fcitx is running correctly.\n\n==="..., 16056) = 87
  51. read(8, "Launch fbterm...\n", 15969) = 17
  52. read(8, "stdin isn't a tty!\n", 15952) = 19
  53. read(8, "__RESULT\0/home/lujun9972/bin:/ho"..., 15933) = 298
  54. read(8, 0x7ffd1d39ce9d, 15635) = ? ERESTARTSYS (To be restarted if SA_RESTART is set)
  55. --- SIGCHLD {si_signo=SIGCHLD, si_code=CLD_EXITED, si_pid=10949, si_uid=1000, si_status=0, si_utime=10, si_stime=7} ---
  56. rt_sigreturn({mask=[]}) = -1 EINTR (被中断的系统调用)
  57. read(8, "", 15635) = 0
  58. wait4(10949, [{WIFEXITED(s) && WEXITSTATUS(s) == 0}], 0, NULL) = 10949
  59. close(8) = 0
  60. getpid() = 10818
  61. faccessat(AT_FDCWD, "/home/lujun9972/bin/printf", X_OK) = -1 ENOENT (没有那个文件或目录)
  62. faccessat(AT_FDCWD, "/usr/local/sbin/printf", X_OK) = -1 ENOENT (没有那个文件或目录)
  63. faccessat(AT_FDCWD, "/usr/local/bin/printf", X_OK) = -1 ENOENT (没有那个文件或目录)
  64. faccessat(AT_FDCWD, "/usr/bin/printf", X_OK) = 0
  65. stat("/usr/bin/printf", {st_mode=S_IFREG|0755, st_size=51176, ...}) = 0
  66. openat(AT_FDCWD, "/dev/null", O_RDONLY|O_CLOEXEC) = 7
  67. faccessat(AT_FDCWD, "/proc/5070/fd/.", F_OK) = 0
  68. faccessat(AT_FDCWD, "/proc/5070/fd/.", F_OK) = 0
  69. faccessat(AT_FDCWD, "/bin/bash", X_OK) = 0
  70. stat("/bin/bash", {st_mode=S_IFREG|0755, st_size=903440, ...}) = 0
  71. pipe2([8, 9], O_CLOEXEC) = 0
  72. rt_sigprocmask(SIG_BLOCK, [INT CHLD], [], 8) = 0
  73. vfork() = 11679
  74. rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
  75. close(9) = 0
  76. close(7) = 0
  77. read(8, "setterm: \347\273\210\347\253\257 xterm-256color \344"..., 16384) = 51
  78. read(8, "Couldn't get a file descriptor r"..., 16333) = 56
  79. read(8, "/home/lujun9972/.bash_profile: \347"..., 16277) = 72
  80. read(8, "Your display number is 0\nTest wh"..., 16205) = 78
  81. read(8, "Fcitx is running correctly.\n\n==="..., 16127) = 104
  82. read(8, "stdin isn't a tty!\n", 16023) = 19
  83. read(8, "__RESULT\0b269cd09e7ec4e8a115188c"..., 16004) = 298
  84. read(8, 0x7ffd1d39cba6, 15706) = ? ERESTARTSYS (To be restarted if SA_RESTART is set)
  85. --- SIGCHLD {si_signo=SIGCHLD, si_code=CLD_EXITED, si_pid=11679, si_uid=1000, si_status=0, si_utime=1, si_stime=1} ---
  86. rt_sigreturn({mask=[]}) = -1 EINTR (被中断的系统调用)
  87. read(8,

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

那么 8 号文件句柄在哪里定义的呢?往前看可以看到:

  1. pipe2([8, 9], O_CLOEXEC) = 0
  2. rt_sigprocmask(SIG_BLOCK, [INT CHLD], [], 8) = 0
  3. vfork() = 11679
  4. rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
  5. close(9) = 0

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

然而,从

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

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

而且从

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

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

在往前翻发现这么一段信息:

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

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

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

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

dotspacemacs-excluded-packages '(exec-path-from-shell)

再次重启Emacs,发现这次启动速度明显快了许多了。

😻:还在看吗?


内容来自用户分享和网络整理,不保证内容的准确性,如有侵权内容,可联系管理员处理 点击这里给我发消息
标签: