在 Emacs 中分析 shell 命令

Posted 2023-03-06

【中文标题】在 Emacs 中分析 shell 命令

【英文标题】：Profiling shell commands in Emacs

【发布时间】：2019-05-21 09:16:49

【问题描述】：

有没有办法分析 emacs 中 shell 命令的阻塞时间？考虑以下程序：

(profiler-start 'cpu)
(shell-command "sleep 3")
(profiler-report)
(profiler-stop)

分析器报告将如下所示：

- command-execute                                                 371  95%
 - call-interactively                                             371  95%
  - funcall-interactively                                         329  84%
   - execute-extended-command                                     175  44%
    - execute-extended-command--shorter                           157  40%
     - completion-try-completion                                  149  38%
      - completion--nth-completion                                149  38%
       - completion--some                                         143  36%
        - #<compiled 0x438307f1>                                  143  36%
         - completion-pcm-try-completion                          102  26%
          - completion-pcm--find-all-completions                   98  25%
             completion-pcm--all-completions                       98  25%
          + completion-pcm--merge-try                               4   1%
           completion-basic-try-completion                         41  10%
    + sit-for                                                      16   4%
   - eval-expression                                              154  39%
    - eval                                                        154  39%
     - profiler-start                                             154  39%
      - debug                                                     154  39%
       - recursive-edit                                           141  36%
        - command-execute                                         114  29%
         - call-interactively                                     114  29%
          - byte-code                                             107  27%
           + read--expression                                      64  16%
           + read-extended-command                                 43  11%
          + funcall-interactively                                   7   1%
  + byte-code                                                      42  10%
+ ...                                                              19   4%

如您所见，所花费的时间或多或少是均匀分布的。我有兴趣看到输出告诉我我将程序的重要部分花费在 shell 命令sleep 3 上，这可能吗？我知道sleep 3 在我的 CPU 上并不重 - 但我试图弄清楚从 magit 调用哪些 shell 命令需要很长时间 - 所以我也会对 IO 的东西感兴趣-绑定。

【问题讨论】：

您可以使用perf 来获取低级调用的调用堆栈，例如。 Fcall_process_region 等假设您的 emacs 二进制文件没有被剥离符号。这可以让您检查 emacs 在给定 CPU 上阻塞所花费的时间，但我不确定您将如何匹配特定的 elisp 调用。

【参考方案1】：

请注意，profiler.el 是一个采样分析器。如果您对挂墙时间感兴趣，您可能想尝试使用诸如elp.el 之类的检测分析器。

在您的情况下，您可能希望使用 M-x elp-instrument-package RET magit RET 来检测 magit。运行 magit 命令后，您可以使用 M-x elp-results RET 查看结果。

对于magit，您可能会发现函数magit-process-file 占用了大量时间。为了进一步调查特定的函数调用，您可以简单地检测该函数或任何其他函数，方法是添加一个建议函数，将运行时连同函数的参数一起记录到每个单独函数调用的消息缓冲区中，如下所示。

(defun log-function-time (f &rest args)
  (let ((time-start (current-time)))
    (prog1
        (apply f args)
      (message "%s seconds used in (magit-process-file %s)"
               (time-to-seconds (time-subtract (current-time) time-start))
               args))))

(advice-add 'magit-process-file :around 'log-function-time)

【讨论】：

这是一个很好的答案。我需要做更多的调查才能弄清楚为什么magit 对我来说这么慢 - 但你肯定为我提供了一些调查工具。干杯! magit 当然会创建许多子流程。 27 次致电magit-process-file 举报git status：S