The call stack result of profile-report doesn't match the real function codes

Question

I'm trying to figure out why my emacs was slow tonight and found:

- command-execute                                               82796  87%
 - call-interactively                                           82792  87%
  - funcall-interactively                                       82792  87%
   - evil-ex-search-forward                                     42805  45%
    - apply                                                     42805  45%
     - #<compiled 0x1891b35>                                    42805  45%
      - apply                                                   42805  45%
       - #<compiled 0x17e0a1d>                                  42802  45%
        - evil-ex-start-search                                  42802  45%
         - read-string                                          42783  45%
          - redisplay_internal (C function)                     42587  45%
           - eval                                               42567  45%
            - awesome-tab-line                                  42557  45%
             - cond                                             42557  45%
              - or                                              42550  45%
               - awesome-tab-line-format                        42550  45%
                - let*                                          42544  45%
                 - while                                        42540  45%
                  - setq                                        42540  45%
                   - cons                                       42540  45%
                    - awesome-tab-line-tab                      42540  45%
                     - propertize                               42540  45%
                      - awesome-tab-buffer-tab-label              42540  45%
                       - let*                                   42540  45%
                        - concat                                42540  45%
                         - if                                   42522  45%
                          - awesome-tab-icon-for-tab              42522  45%
                           - if                                 42522  45%
                            - and                               42380  45%
                             - condition-case                   42374  45%
                                progn                           42374  45%
                            + progn                               142   0%

As the result shows, awesome-tab-icon-for-tab is the root cause. Here is the definition of awesome-tab-icon-for-tab:

(defun awesome-tab-icon-for-tab (tab face)
  "When tab buffer's file is exists, use `all-the-icons-icon-for-file' to fetch file icon.
Otherwise use `all-the-icons-icon-for-buffer' to fetch icon for buffer."
  (when (and awesome-tab-display-icon
             (ignore-errors (require 'all-the-icons)))
    (let* ((tab-buffer (car tab))
           (tab-file (buffer-file-name tab-buffer))
           (background (face-background face))
           (icon
            (cond
             ;; Use `all-the-icons-icon-for-file' if current file is exists.
             ((and
               tab-file
               (file-exists-p tab-file))
              (all-the-icons-icon-for-file tab-file :v-adjust awesome-tab-icon-v-adjust :height awesome-tab-icon-height))
             ;; Use `all-the-icons-icon-for-mode' for current tab buffer at last.
             (t
              (with-current-buffer tab-buffer
                (all-the-icons-icon-for-mode major-mode :v-adjust awesome-tab-icon-v-adjust :height awesome-tab-icon-height)
                )))))
      (when (and icon
                 ;; `get-text-property' need icon is string type.
                 (stringp icon))
        ;; Thanks ema2159 for code block ;)
        (propertize
         icon
         'face `(:inherit ,(get-text-property 0 'face icon)
                          :background ,background
                          ))))))

the profile tells me that

- awesome-tab-icon-for-tab              42522  45%
                           - if                                 42522  45%
                            - and                               42380  45%
                             - condition-case                   42374  45%
                                progn                           42374  45%

But the definition of awesome-tab-icon-for-tab contain none of if, and, condition-case and prog.

What happened?

Answer 1

Let's have a look at

(when (and awesome-tab-display-icon
             (ignore-errors (require 'all-the-icons)))

when is a macro defined in subr.el:

(defmacro when (cond &rest body)
  "If COND yields non-nil, do BODY, else return nil.
When COND yields non-nil, eval BODY forms sequentially and return
value of last one, or nil if there are none.

\(fn COND BODY...)"
  (declare (indent 1) (debug t))
  (list 'if cond (cons 'progn body)))

There you have if. The and is present in the original code.

ignore-errors is also a macro defined in subr.el:

(defmacro ignore-errors (&rest body)
  "Execute BODY; if an error occurs, return nil.
Otherwise, return result of last form in BODY.
See also `with-demoted-errors' that does something similar
without silencing all errors."
  (declare (debug t) (indent 0))
  `(condition-case nil (progn ,@body) (error nil)))

There you have condition-case and progn.

The macros are expanded in the compiled code. Therefore, you get their expansions in the profiler output instead of their names.