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?

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: stackoverflow.com/questions/23622296/… Commented Aug 15, 2018 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. Commented Aug 15, 2018 at 17:46

0

Start asking to get answers

Find the answer to your question by asking.

Ask question

Explore related questions

See similar questions with these tags.