Testing if it will be slower to make a macro calling a separate function or SBCL will optimize

test-macro-optimization.lisp

(uiop:define-package #:test-macro-optimization
  (:use #:cl)
  (:documentation "Checking if lambda function will be optimized away depending on optimization settings."))
(in-package #:test-macro-optimization)

;; (declaim (optimize (debug 0) (safety 0) (speed 3)))

;; (declaim (optimize (debug 3) (safety 1) (speed 1)))

;; (declaim (optimize (debug 3) (safety 3) (speed 1)))

;; (declaim (optimize (debug 3) (safety 3) (speed 1)))

;; TEST-MACRO-OPTIMIZATION> (time (loop repeat 100000000
;;                                      do (use-plain "foo")))
;; Evaluation took:
;;   7.637 seconds of real time
;;   7.487740 seconds of total run time (7.404328 user, 0.083412 system)
;;   [ Real times consist of 0.115 seconds GC time, and 7.522 seconds non-GC time. ]
;;   [ Run times consist of 0.113 seconds GC time, and 7.375 seconds non-GC time. ]
;;   98.05% CPU
;;   17,600,047,920 bytes consed

;; TEST-MACRO-OPTIMIZATION> (time (loop repeat 100000000
;;                                      do (use-wrapped "foo")))
;; Evaluation took:
;;   3.252 seconds of real time
;;   3.223868 seconds of total run time (3.167369 user, 0.056499 system)
;;   [ Real times consist of 0.040 seconds GC time, and 3.212 seconds non-GC time. ]
;;   [ Run times consist of 0.039 seconds GC time, and 3.185 seconds non-GC time. ]
;;   99.14% CPU
;;   6,399,983,472 bytes consed

;; WITHOUT DYNAMIC EXTENT

;; TEST-MACRO-OPTIMIZATION> (time (loop repeat 100000000
;;                                      do (use-wrapped "foo")))
;; Evaluation took:
;;   3.311 seconds of real time
;;   3.287290 seconds of total run time (3.230978 user, 0.056312 system)
;;   [ Real times consist of 0.042 seconds GC time, and 3.269 seconds non-GC time. ]
;;   [ Run times consist of 0.038 seconds GC time, and 3.250 seconds non-GC time. ]
;;   99.28% CPU
;;   6,399,983,440 bytes consed


(declaim (optimize (debug 1) (safety 1) (speed 3)))

;; TEST-MACRO-OPTIMIZATION> (time (loop repeat 100000000
;;                                      do (use-plain "foo")))
;; Evaluation took:
;;   7.277 seconds of real time
;;   7.188132 seconds of total run time (7.109495 user, 0.078637 system)
;;   [ Real times consist of 0.107 seconds GC time, and 7.170 seconds non-GC time. ]
;;   [ Run times consist of 0.106 seconds GC time, and 7.083 seconds non-GC time. ]
;;   98.78% CPU
;;   17,599,982,368 bytes consed

;; TEST-MACRO-OPTIMIZATION> (time (loop repeat 100000000
;;                                      do (use-wrapped "foo")))
;; Evaluation took:
;;   1.220 seconds of real time
;;   1.225998 seconds of total run time (1.213081 user, 0.012917 system)
;;   [ Real times consist of 0.041 seconds GC time, and 1.179 seconds non-GC time. ]
;;   [ Run times consist of 0.041 seconds GC time, and 1.185 seconds non-GC time. ]
;;   100.49% CPU
;;   6,399,982,704 bytes consed

;;; WITHOUT dynamic extent

;; TEST-MACRO-OPTIMIZATION> (time (loop repeat 100000000
;;                                      do (use-wrapped "foo")))
;; Evaluation took:
;;   1.238 seconds of real time
;;   1.238246 seconds of total run time (1.224682 user, 0.013564 system)
;;   [ Real times consist of 0.040 seconds GC time, and 1.198 seconds non-GC time. ]
;;   [ Run times consist of 0.039 seconds GC time, and 1.200 seconds non-GC time. ]
;;   100.00% CPU
;;   6,399,982,656 bytes consed

;; WITHOUT inline and type declaration for call-wrapped USE-WRAPPED is slower

;; TEST-MACRO-OPTIMIZATION> (time (loop repeat 100000000
;;                                      do (use-plain "foo")))
;; Evaluation took:
;;   7.052 seconds of real time
;;   7.043645 seconds of total run time (6.970709 user, 0.072936 system)
;;   [ Real times consist of 0.108 seconds GC time, and 6.944 seconds non-GC time. ]
;;   [ Run times consist of 0.108 seconds GC time, and 6.936 seconds non-GC time. ]
;;   99.89% CPU
;;   17,599,950,720 bytes consed
  
;; NIL
;; TEST-MACRO-OPTIMIZATION> (time (loop repeat 100000000
;;                                      do (use-wrapped "foo")))
;; Evaluation took:
;;   7.527 seconds of real time
;;   7.529097 seconds of total run time (7.491302 user, 0.037795 system)
;;   [ Real times consist of 0.107 seconds GC time, and 7.420 seconds non-GC time. ]
;;   [ Run times consist of 0.107 seconds GC time, and 7.423 seconds non-GC time. ]
;;   100.03% CPU
;;   17,600,047,728 bytes consed

;; WITH only type declaration for call-wrapped USE-WRAPPED is faster

;; TEST-MACRO-OPTIMIZATION> (time (loop repeat 100000000
;;                                      do (use-plain "foo")))
;; Evaluation took:
;;   7.071 seconds of real time
;;   7.049726 seconds of total run time (6.976541 user, 0.073185 system)
;;   [ Real times consist of 0.107 seconds GC time, and 6.964 seconds non-GC time. ]
;;   [ Run times consist of 0.107 seconds GC time, and 6.943 seconds non-GC time. ]
;;   99.70% CPU
;;   17,599,947,520 bytes consed
  
;; TEST-MACRO-OPTIMIZATION> (time (loop repeat 100000000
;;                                      do (use-wrapped "foo")))
;; Evaluation took:
;;   1.234 seconds of real time
;;   1.239893 seconds of total run time (1.226658 user, 0.013235 system)
;;   [ Real times consist of 0.041 seconds GC time, and 1.193 seconds non-GC time. ]
;;   [ Run times consist of 0.041 seconds GC time, and 1.199 seconds non-GC time. ]
;;   100.49% CPU
;;   6,399,982,752 bytes consed

;; IF FIRST ARGUEMENT TYPE omitted in FTYPE declaraion

;; TEST-MACRO-OPTIMIZATION> (time (loop repeat 100000000
;;                                      do (use-wrapped "foo")))
;; Evaluation took:
;;   7.526 seconds of real time
;;   7.537720 seconds of total run time (7.497798 user, 0.039922 system)
;;   [ Real times consist of 0.122 seconds GC time, and 7.404 seconds non-GC time. ]
;;   [ Run times consist of 0.122 seconds GC time, and 7.416 seconds non-GC time. ]
;;   100.16% CPU
;;   17,599,982,336 bytes consed



;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;; 

;; (declaim (optimize (debug 1) (safety 1) (speed 1)))

;; TEST-MACRO-OPTIMIZATION> (time (loop repeat 100000000
;;                                      do (use-plain "foo")))
;; Evaluation took:
;;   7.246 seconds of real time
;;   7.133859 seconds of total run time (7.085236 user, 0.048623 system)
;;   [ Real times consist of 0.108 seconds GC time, and 7.138 seconds non-GC time. ]
;;   [ Run times consist of 0.108 seconds GC time, and 7.026 seconds non-GC time. ]
;;   98.45% CPU
;;   17,599,982,592 bytes consed

;; TEST-MACRO-OPTIMIZATION> (time (loop repeat 100000000
;;                                      do (use-wrapped "foo")))
;; Evaluation took:
;;   2.960 seconds of real time
;;   2.961433 seconds of total run time (2.934970 user, 0.026463 system)
;;   [ Real times consist of 0.039 seconds GC time, and 2.921 seconds non-GC time. ]
;;   [ Run times consist of 0.039 seconds GC time, and 2.923 seconds non-GC time. ]
;;   100.03% CPU
;;   6,399,982,704 bytes consed

;;; WITHOUT DYNAMIC EXTENT

;; TEST-MACRO-OPTIMIZATION> (time (loop repeat 100000000
;;                                      do (use-wrapped "foo")))
;; Evaluation took:
;;   2.963 seconds of real time
;;   2.958848 seconds of total run time (2.943937 user, 0.014911 system)
;;   [ Real times consist of 0.040 seconds GC time, and 2.923 seconds non-GC time. ]
;;   [ Run times consist of 0.040 seconds GC time, and 2.919 seconds non-GC time. ]
;;   99.87% CPU
;;   6,399,982,688 bytes consed


;; (declaim (optimize (debug 0) (safety 0) (speed 3)))

;; TEST-MACRO-OPTIMIZATION> (time (loop repeat 100000000
;;                                      do (use-plain "foo")))
;; Evaluation took:
;;   7.055 seconds of real time
;;   7.050692 seconds of total run time (7.011514 user, 0.039178 system)
;;   [ Real times consist of 0.108 seconds GC time, and 6.947 seconds non-GC time. ]
;;   [ Run times consist of 0.106 seconds GC time, and 6.945 seconds non-GC time. ]
;;   99.94% CPU
;;   17,599,982,320 bytes consed
  
;; TEST-MACRO-OPTIMIZATION> (time (loop repeat 100000000
;;                                      do (use-wrapped "foo")))
;; Evaluation took:
;;   1.234 seconds of real time
;;   1.240215 seconds of total run time (1.227776 user, 0.012439 system)
;;   [ Real times consist of 0.037 seconds GC time, and 1.197 seconds non-GC time. ]
;;   [ Run times consist of 0.037 seconds GC time, and 1.204 seconds non-GC time. ]
;;   100.49% CPU
;;   6,399,982,960 bytes consed

;; WITHOUT DYNAMIC EXTENT

;; TEST-MACRO-OPTIMIZATION> (time (loop repeat 100000000
;;                                      do (use-wrapped "foo")))
;; Evaluation took:
;;   1.247 seconds of real time
;;   1.248188 seconds of total run time (1.223103 user, 0.025085 system)
;;   [ Real times consist of 0.040 seconds GC time, and 1.207 seconds non-GC time. ]
;;   [ Run times consist of 0.040 seconds GC time, and 1.209 seconds non-GC time. ]
;;   100.08% CPU
;;   6,399,982,624 bytes consed

;; WITH INLINE

;; TEST-MACRO-OPTIMIZATION> (time (loop repeat 100000000
;;                                      do (use-wrapped "foo")))
;; Evaluation took:
;;   1.060 seconds of real time
;;   1.061276 seconds of total run time (1.048440 user, 0.012836 system)
;;   [ Real times consist of 0.040 seconds GC time, and 1.020 seconds non-GC time. ]
;;   [ Run times consist of 0.040 seconds GC time, and 1.022 seconds non-GC time. ]
;;   100.09% CPU
;;   6,399,982,640 bytes consed


(defparameter *compiler-optimizations*
  #.(quote
     (sb-cltl2:declaration-information 'optimize)))


;; Эта версия получается медленнее просто потому что у компилятора нет
;; информации о типе name и он вынужден вызывать функцию форматирования,
;; тогда как если для call-wrapped указать тип аргумента name,
;; то он может оптимизировать и вместо вызова форматирования как-то
;; конкатенировать строки или что-то типа того:
(defmacro plain ((name) &body body)
  `(values
    (format nil "Hello ~A!"
            ,name)
    (progn
      ,@body)))


;; (declaim (ftype (function (string function))
;;                 call-wrapped))

(declaim (ftype (function (t function))
                call-wrapped))

;; (declaim (notinline call-wrapped))

;; (declaim (inline call-wrapped))

;; (declaim (sb-ext:maybe-inline call-wrapped))

(defun call-wrapped (name thunk)
  (values 
   (format nil "Hello ~A!"
           name)
   (funcall thunk)))


(defmacro wrapped ((name) &body body)
  `(flet ((wrapped-thunk ()
            ,@body))
     ;; (declare (dynamic-extent #'wrapped-thunk))
     (call-wrapped ,name #'wrapped-thunk)))


(defun use-plain (name)
  (plain (name)
    :done))


(defun use-wrapped (name)
  (wrapped (name)
    :done))


(defun show ()
  (format t "Optimizations:~2%~A"
          *compiler-optimizations*)
  
  (format t "~2%USE-PLAIN:~2%")
  (disassemble #'use-plain)
  
  (format t "~2%USE-WRAPPED:~2%")
  (disassemble #'use-wrapped)
  (terpri))