3

I'm trying to profile the usually excellent find-things-fast package to figure out why it's slow in my project.

I started profiling with profiler-start, executed the command that's slow (ftf-find-file), then immediately ran profiler-report.

This generated the following report:

Functions                                                 CPU samples  %
- command-execute                                                1770  88%
 - call-interactively                                            1770  88%
  - apply                                                        1770  88%
   - call-interactively@ido-cr+-record-current-command               1770  88%
    - apply                                                      1770  88%
     - #<subr call-interactively>                                1770  88%
      - funcall-interactively                                    1770  88%
       - ftf-find-file                                           1597  80%
        - ftf-project-files-alist                                1522  76%
         - ftf-project-files-hash                                1330  66%
          - let                                                  1330  66%
           - mapcar                                              1330  66%
            - #<lambda 0x5458e8e0>                               1024  51%
             - let*                                              1008  50%
                cons                                               24   1%
            + split-string                                        282  14%
         + maphash                                                192   9%
        + ido-completing-read                                      67   3%
       + next-line                                                 75   3%
       + ido-switch-buffer                                         41   2%
       + ido-switch-buffer-other-window                            38   1%
       + profiler-report                                           19   0%
+ ...                                                             145   7%
+ redisplay_internal (C function)                                  37   1%
+ timer-event-handler                                              26   1%
  undefined                                                         5   0%
+ gui-set-selection                                                 4   0%
  internal-echo-keystrokes-prefix                                   2   0%

The profiler report seems to blame the let* function within ftf-project-files-hash.

However, looking at that function:

(defun ftf-project-files-hash ()
  "Returns a hashtable filled with file names as the key and "
  (let ((default-directory (ftf-project-directory))
        (table (make-hash-table :test 'equal)))
    (mapcar (lambda (file)
              (let* ((file-name (file-name-nondirectory file))
                     (full-path (expand-file-name file))
                     (pathlist (cons full-path (gethash file-name table nil))))
                (puthash file-name pathlist table)))
            (split-string (ftf-project-files-string)))
    table))

It seems incredibly unlikely that let* is the slow part, but rather one of the functions called within that let*.

Why is profiler-report stopping at let* rather than telling me which component of that let* is slow? How can I dig deeper to find which exactly function is slow?

zeptonaut
  • 131
  • 2
  • You might want to try adding a message before the mapcar section to see how big the list is, e.g., (message "length: %s" (length (split-string (ftf-project-files-string)))). It may be that you are just dealing with a lot of stuff that needs to be processed. It may also be that the function itself ftf-project-files-string is time consuming, and you might want to put a measure-time wrapper around it. See: https://stackoverflow.com/questions/23622296/emacs-timing-execution-of-function-calls-in-emacs-lisp – lawlist Aug 15 '18 at 17:36
  • FYI, it does not appear that the measure-time macro throws the result of whatever it wraps (but I could be wrong), and the mapcar needs the result of ftf-project-files-string via (split-string ...). Thus, you may want to put a separate measure-time statement with (measure-time (ftf-project-files-string)) before the mapcar statement to do some debugging. Of course, the profiler would then show double the time because that function would be called twice -- however, it is just for debugging to get a sense of the time cost. – lawlist Aug 15 '18 at 17:46

0 Answers0