Профилирование команд оболочки в Emacs - PullRequest
Новая
       40

Профилирование команд оболочки в Emacs

8 голосов
/ 21 мая 2019

Есть ли способ профилировать количество времени блокировки команд оболочки в emacs? Рассмотрим следующую программу: 

(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%

Как видите, затраченное время распределяется более или менее равномерно. Мне интересно увидеть вывод, который говорит мне, что я трачу значительную часть блокировки программы на команду оболочки sleep 3, возможно ли это как-то? Я знаю, что sleep 3 не сильно загружает мой процессор - но я пытаюсь выяснить, какие команды оболочки вызываются из magit, что занимает так много времени - поэтому я также буду интересоваться вещами, которые являются IO -связанные.

1 Ответ

4 голосов
/ 31 мая 2019

Обратите внимание, что profiler.el является профилировщиком выборки. Возможно, вы захотите попробовать профилировщик инструментов, такой как elp.el, если вы заинтересованы в настенном времени.

В вашем случае вы можете использовать инструмент magit, используя M-x elp-instrument-package RET magit RET . После запуска команд 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)
...