lispci/fiveam

DEF-TEST eats CPU and conses like crazy

phoe opened this issue · 3 comments

phoe commented

I'm on SBCL 1.3.11 on Linux.

(ql:quickload :fiveam)
(use-package :fiveam)
(def-test foo-test () 
  #.(cons 'progn (make-list 100 :initial-element '(is (equalp (cons 2 4) (cons 2 4))))))

This causes my SBCL to eat up all of its CPU, then eat up all of its memory, and finally crash and burn because of heap exhaustion.

I #'TIMEd the runs and here are the results. Pay attention to the #'MAKE-LIST list length as it changes from 2 to 64.

CL-USER> (ql:quickload :fiveam)
CL-USER> (use-package :fiveam)

CL-USER> (time (def-test foo-test () #.(cons 'progn (make-list 2 :initial-element '(is (equalp (cons 2 4) (cons 2 4)))))))
Evaluation took:
  0.091 seconds of real time
  0.088000 seconds of total run time (0.068000 user, 0.020000 system)
  [ Run times consist of 0.032 seconds GC time, and 0.056 seconds non-GC time. ]
  96.70% CPU
  1 form interpreted
  113 lambdas converted
  228,201,148 processor cycles
  10,766,368 bytes consed
  
FOO-TEST
CL-USER> (time (def-test foo-test () #.(cons 'progn (make-list 4 :initial-element '(is (equalp (cons 2 4) (cons 2 4)))))))
Evaluation took:
  0.143 seconds of real time
  0.144000 seconds of total run time (0.144000 user, 0.000000 system)
  100.70% CPU
  1 form interpreted
  223 lambdas converted
  358,371,848 processor cycles
  27,275,104 bytes consed
  
FOO-TEST
CL-USER> (time (def-test foo-test () #.(cons 'progn (make-list 8 :initial-element '(is (equalp (cons 2 4) (cons 2 4)))))))
Evaluation took:
  0.531 seconds of real time
  0.480000 seconds of total run time (0.464000 user, 0.016000 system)
  [ Run times consist of 0.116 seconds GC time, and 0.364 seconds non-GC time. ]
  90.40% CPU
  1 form interpreted
  443 lambdas converted
  1,333,272,895 processor cycles
  78,526,736 bytes consed
  
FOO-TEST
CL-USER> (time (def-test foo-test () #.(cons 'progn (make-list 16 :initial-element '(is (equalp (cons 2 4) (cons 2 4)))))))
Evaluation took:
  2.100 seconds of real time
  1.980000 seconds of total run time (1.880000 user, 0.100000 system)
  [ Run times consist of 0.356 seconds GC time, and 1.624 seconds non-GC time. ]
  94.29% CPU
  1 form interpreted
  883 lambdas converted
  5,272,793,292 processor cycles
  254,015,344 bytes consed
  
FOO-TEST
CL-USER> (time (def-test foo-test () #.(cons 'progn (make-list 32 :initial-element '(is (equalp (cons 2 4) (cons 2 4)))))))
Evaluation took:
  11.481 seconds of real time
  11.316000 seconds of total run time (10.888000 user, 0.428000 system)
  [ Run times consist of 1.844 seconds GC time, and 9.472 seconds non-GC time. ]
  98.56% CPU
  1 form interpreted
  1,763 lambdas converted
  28,827,998,226 processor cycles
  895,486,432 bytes consed
  
FOO-TEST
CL-USER> (time (def-test foo-test () #.(cons 'progn (make-list 64 :initial-element '(is (equalp (cons 2 4) (cons 2 4)))))))
;; heap exhaustion
phoe commented

Also posted by PuercoPop on #lisp:

(sb-sprof:with-profiling (:mode :alloc :report :flat :max-samples 1000) (def-test foo-test () #.(cons 'progn (make-list 10
                                                                                                                                 :initial-element '(is (equalp (cons 2 4) (cons 2 4)))))))

Profiler sample vector full (96 traces / 10000 samples), doubling the size
Profiler sample vector full (278 traces / 20000 samples), doubling the size
Profiler sample vector full (660 traces / 40000 samples), doubling the size

Number of samples:     1000
Alloc interval:        4 regions (approximately 128 kB)
Total sampling amount: 4000 regions (approximately 128000 kB)
Number of cycles:      0
Sampled threads:
   #<SB-THREAD:THREAD "sly-channel-1-mrepl-remote-1" RUNNING {1002451083}>

           Self        Total        Cumul
  Nr  Count     %  Count     %  Count     %    Calls  Function
------------------------------------------------------------------------
   1    381  38.1    381  38.1    381  38.1        -  SB-C::MAKE-GLOBAL-CONFLICTS
   2    289  28.9    298  29.8    670  67.0        -  SB-C::COPY-CONSET
   3     57   5.7     57   5.7    727  72.7        -  SB-C::MAKE-CONSET
   4     27   2.7     27   2.7    754  75.4        -  SB-REGALLOC::INIT-SB-VECTORS
   5     13   1.3     13   1.3    767  76.7        -  SB-C::MAKE-REF
   6     12   1.2     12   1.2    779  77.9        -  MAKE-HASH-TABLE
   7     10   1.0     10   1.0    789  78.9        -  SB-C::MAKE-TN
   8     10   1.0     10   1.0    799  79.9        -  SB-C:MAKE-TN-REF
   9      9   0.9      9   0.9    808  80.8        -  SB-PRETTY::MAKE-PRETTY-STREAM
  10      9   0.9      9   0.9    817  81.7        -  SB-C::MAKE-LVAR
  11      9   0.9      9   0.9    826  82.6        -  COPY-STRUCTURE
  12      9   0.9      9   0.9    835  83.5        -  SB-C::MAKE-IR2-BLOCK
  13      7   0.7      7   0.7    842  84.2        -  SB-KERNEL:MAKE-SINGLE-VALUE-TYPE
  14      7   0.7      7   0.7    849  84.9        -  SB-INT:COPY-SSET
  15      7   0.7      7   0.7    856  85.6        -  SB-C::MAKE-VOP
  16      6   0.6     15   1.5    862  86.2        -  SB-C::CONSTRAIN-REF-TYPE
  17      6   0.6      6   0.6    868  86.8        -  SB-C::MAKE-BLOCK
  18      6   0.6      6   0.6    874  87.4        -  SB-IMPL::ALLOC-HASH-CACHE-LINE/4
  19      5   0.5      5   0.5    879  87.9        -  SB-C::MAKE-CTRAN
  20      5   0.5      5   0.5    884  88.4        -  (FLET #:CLEANUP-FUN-450 :IN SB-THREAD::CALL-WITH-RECURSIVE-SYSTEM-LOCK/WITHOUT-GCING)
  21      5   0.5      5   0.5    889  88.9        -  SB-C::SSET-GROW
  22      4   0.4      4   0.4    893  89.3        -  SB-IMPL::ALLOCATE-VECTOR-WITH-WIDETAG
  23      4   0.4      4   0.4    897  89.7        -  SB-C::MAKE-BLOCK-KEY
  24      4   0.4      4   0.4    901  90.1        -  SB-C::MAKE-LEXENV
  25      4   0.4      4   0.4    905  90.5        -  SB-C::MAKE-LAMBDA
  26      4   0.4      4   0.4    909  90.9        -  SB-C::INHERIT-CONSTRAINTS
  27      3   0.3      3   0.3    912  91.2        -  SB-KERNEL:LIST-SUBSEQ*
  28      3   0.3      3   0.3    915  91.5        -  SB-C::MAKE-RETURN
  29      3   0.3      3   0.3    918  91.8        -  REMOVE
  30      3   0.3      3   0.3    921  92.1        -  SB-C::%CONSET-GROW
  31      3   0.3      3   0.3    924  92.4        -  SB-KERNEL:TYPE-DIFFERENCE
  32      2   0.2      5   0.5    926  92.6        -  SB-C::PROPAGATE-LET-ARGS
  33      2   0.2      4   0.4    928  92.8        -  SB-C::LINK-BLOCKS
  34      2   0.2      4   0.4    930  93.0        -  SB-C::UPDATE-UVL-LIVE-SETS
  35      2   0.2      2   0.2    932  93.2        -  SB-C::%LINK-BLOCKS
  36      2   0.2      2   0.2    934  93.4        -  SB-IMPL::%MAKE-STRING-OUTPUT-STREAM
  37      2   0.2      2   0.2    936  93.6        -  SB-C::EXTRACT-LET-VARS
  38      2   0.2      2   0.2    938  93.8        -  SB-PRETTY::START-LOGICAL-BLOCK
  39      2   0.2      2   0.2    940  94.0        -  SB-C::%MAKE-CAST
  40      2   0.2      2   0.2    942  94.2        -  SB-INT:PARSE-LAMBDA-LIST
  41      2   0.2      2   0.2    944  94.4        -  SB-C::MAKE-BIND
  42      2   0.2      2   0.2    946  94.6        -  SB-C::%MAKE-INTERVAL
  43      2   0.2      2   0.2    948  94.8        -  SB-C::MAKE-COMBINATION
  44      2   0.2      2   0.2    950  95.0        -  APPEND
  45      2   0.2      2   0.2    952  95.2        -  SB-C::PREPARE-ARG-FOR-DERIVE-TYPE
  46      2   0.2      2   0.2    954  95.4        -  SB-IMPL::ALLOC-HASH-CACHE-LINE/3
  47      2   0.2      2   0.2    956  95.6        -  SB-KERNEL::%MAKE-VALUES-TYPE
  48      2   0.2      2   0.2    958  95.8        -  SB-INT:ALLOC-XSET
  49      2   0.2      2   0.2    960  96.0        -  SB-C::MAP-BLOCK-NLXES
  50      2   0.2      2   0.2    962  96.2        -  SB-INT:MAKE-SSET
  51      1   0.1    233  23.3    963  96.3        -  SB-C::FIND-BLOCK-TYPE-CONSTRAINTS
  52      1   0.1      9   0.9    964  96.4        -  SB-C::REFERENCE-LEAF
  53      1   0.1      6   0.6    965  96.5        -  SB-C::ADD-EQL-VAR-VAR-CONSTRAINT
  54      1   0.1      4   0.4    966  96.6        -  SB-KERNEL:%MAKE-ARRAY
  55      1   0.1      2   0.2    967  96.7        -  (MACRO-FUNCTION DOTIMES)
  56      1   0.1      2   0.2    968  96.8        -  SB-C::FIND-DFO-AUX
  57      1   0.1      1   0.1    969  96.9        -  SB-PRETTY::ENQUEUE-NEWLINE
  58      1   0.1      1   0.1    970  97.0        -  SB-IMPL::STRING-OUTPUT-STREAM-NEW-BUFFER
  59      1   0.1      1   0.1    971  97.1        -  SB-UNICODE::DECOMPOSE-STRING
  60      1   0.1      1   0.1    972  97.2        -  (MACRO-FUNCTION POP)
  61      1   0.1      1   0.1    973  97.3        -  SB-PRETTY::MAKE-BLOCK-END
  62      1   0.1      1   0.1    974  97.4        -  (LABELS SB-C::WALK :IN SB-C::DEBUG-NAME)
  63      1   0.1      1   0.1    975  97.5        -  (LABELS SB-C::HANDLE-FUNCTIONAL :IN SB-C::CALL-WITH-BLOCK-EXTERNAL-FUNCTIONALS)
  64      1   0.1      1   0.1    976  97.6        -  SB-FORMAT::EXPAND-DIRECTIVE
  65      1   0.1      1   0.1    977  97.7        -  SB-C::MAKE-IF
  66      1   0.1      1   0.1    978  97.8        -  SB-C::MAKE-TAIL-SET
  67      1   0.1      1   0.1    979  97.9        -  SB-C::MAKE-ENTRY
  68      1   0.1      1   0.1    980  98.0        -  SB-KERNEL::UNION-UNPARSE-TYPE-METHOD
  69      1   0.1      1   0.1    981  98.1        -  SB-KERNEL:%MAKE-SYMBOL
  70      1   0.1      1   0.1    982  98.2        -  SB-KERNEL::NUMBER-UNPARSE-TYPE-METHOD
  71      1   0.1      1   0.1    983  98.3        -  (MACRO-FUNCTION COND)
  72      1   0.1      1   0.1    984  98.4        -  SB-C::MAKE-EXIT
  73      1   0.1      1   0.1    985  98.5        -  (FLET SB-IMPL::FROB-DO-BODY :IN "SYS:SRC;CODE;DEFBOOT.LISP")
  74      1   0.1      1   0.1    986  98.6        -  SB-C::ENSURE-SOURCE-PATH
  75      1   0.1      1   0.1    987  98.7        -  SB-KERNEL::UNION-COMPLEX-SUBTYPEP-ARG2
  76      1   0.1      1   0.1    988  98.8        -  SB-C::ADD-LVAR-USE
  77      1   0.1      1   0.1    989  98.9        -  SB-KERNEL::FIXED-VALUES-OP
  78      1   0.1      1   0.1    990  99.0        -  SB-C::MAKE-CONSTANT
  79      1   0.1      1   0.1    991  99.1        -  (MACRO-FUNCTION PROG1)
  80      1   0.1      1   0.1    992  99.2        -  SB-C::MAYBE-NEGATE-CHECK
  81      1   0.1      1   0.1    993  99.3        -  SB-C::PRECISE-ADD-COMPLEMENT-CONSTRAINTS
  82      1   0.1      1   0.1    994  99.4        -  (FLET SB-C::BODY-FUN :IN SB-C::ADD-EQL-VAR-VAR-CONSTRAINT)
  83      1   0.1      1   0.1    995  99.5        -  SB-C::NCONC-NEW
  84      1   0.1      1   0.1    996  99.6        -  SB-C::EMIT-CLEANUPS
  85      1   0.1      1   0.1    997  99.7        -  "foreign function pthread_sigmask"
  86      1   0.1      1   0.1    998  99.8        -  SB-C::MAKE-IR2-LVAR
  87      1   0.1      1   0.1    999  99.9        -  SB-KERNEL:%ADJOIN-EQ
  88      1   0.1      1   0.1   1000 100.0        -  SB-REGALLOC::GROW-SC
  89      0   0.0   1000 100.0   1000 100.0        -  SB-C::%COMPILE
  90      0   0.0   1000 100.0   1000 100.0        -  (FLET #:WITHOUT-INTERRUPTS-BODY-387 :IN SB-THREAD::CALL-WITH-RECURSIVE-LOCK)
  91      0   0.0   1000 100.0   1000 100.0        -  SB-THREAD::CALL-WITH-RECURSIVE-LOCK
  92      0   0.0   1000 100.0   1000 100.0        -  (LAMBDA NIL :IN SB-C::ACTUALLY-COMPILE)
  93      0   0.0   1000 100.0   1000 100.0        -  (FLET SB-C::WITH-IT :IN SB-C::%WITH-COMPILATION-UNIT)
  94      0   0.0   1000 100.0   1000 100.0        -  SB-C::ACTUALLY-COMPILE
  95      0   0.0   1000 100.0   1000 100.0        -  SB-C:COMPILE-IN-LEXENV
  96      0   0.0   1000 100.0   1000 100.0        -  SB-IMPL::%SIMPLE-EVAL
  97      0   0.0   1000 100.0   1000 100.0        -  SB-INT:SIMPLE-EVAL-IN-LEXENV
  98      0   0.0   1000 100.0   1000 100.0        -  EVAL
  99      0   0.0   1000 100.0   1000 100.0        -  IT.BESE.FIVEAM::REGISTER-TEST
 100      0   0.0   1000 100.0   1000 100.0        -  "Unknown component: #x22A12050"
 101      0   0.0   1000 100.0   1000 100.0        -  (LAMBDA NIL :IN SLYNK-MREPL::MREPL-EVAL-1)
 102      0   0.0   1000 100.0   1000 100.0        -  SLYNK::CALL-WITH-RETRY-RESTART
 103      0   0.0   1000 100.0   1000 100.0        -  (LAMBDA NIL :IN SLYNK::CALL-WITH-LISTENER)
 104      0   0.0   1000 100.0   1000 100.0        -  SLYNK::CALL-WITH-BINDINGS
 105      0   0.0   1000 100.0   1000 100.0        -  SLYNK::CALL-WITH-LISTENER
 106      0   0.0   1000 100.0   1000 100.0        -  SLYNK-MREPL::MREPL-EVAL-1
 107      0   0.0   1000 100.0   1000 100.0        -  SLYNK-MREPL::MREPL-EVAL
 108      0   0.0   1000 100.0   1000 100.0        -  (SB-PCL::FAST-METHOD SLYNK::CHANNEL-SEND (SLYNK-MREPL::MREPL (EQL (QUOTE :PROCESS)) T))
 109      0   0.0   1000 100.0   1000 100.0        -  (LAMBDA (SB-PCL::.PV. SB-PCL::.NEXT-METHOD-CALL. SB-PCL::.ARG0. SB-PCL::.ARG1. SB-PCL::.ARG2.))
 110      0   0.0   1000 100.0   1000 100.0        -  SLYNK::PROCESS-REQUESTS
 111      0   0.0   1000 100.0   1000 100.0        -  (LAMBDA NIL :IN SLYNK::SPAWN-CHANNEL-THREAD)
 112      0   0.0   1000 100.0   1000 100.0        -  SLYNK-SBCL::CALL-WITH-BREAK-HOOK
 113      0   0.0   1000 100.0   1000 100.0        -  (FLET SLYNK-BACKEND:CALL-WITH-DEBUGGER-HOOK :IN "/home/puercopop/.emacs.d/site-lisp/sly/slynk/backend/sbcl.lisp")
 114      0   0.0   1000 100.0   1000 100.0        -  SLYNK-BACKEND:CALL-WITH-DEBUGGER-HOOK
 115      0   0.0   1000 100.0   1000 100.0        -  (FLET #:FORM-FUN-3522 :IN SLYNK::SPAWN-CHANNEL-THREAD)
 116      0   0.0   1000 100.0   1000 100.0        -  (FLET #:WITHOUT-INTERRUPTS-BODY-1158 :IN SB-THREAD::INITIAL-THREAD-FUNCTION-TRAMPOLINE)
 117      0   0.0   1000 100.0   1000 100.0        -  (FLET SB-THREAD::WITH-MUTEX-THUNK :IN SB-THREAD::INITIAL-THREAD-FUNCTION-TRAMPOLINE)
 118      0   0.0   1000 100.0   1000 100.0        -  (FLET #:WITHOUT-INTERRUPTS-BODY-359 :IN SB-THREAD::CALL-WITH-MUTEX)
 119      0   0.0   1000 100.0   1000 100.0        -  SB-THREAD::CALL-WITH-MUTEX
 120      0   0.0   1000 100.0   1000 100.0        -  SB-THREAD::INITIAL-THREAD-FUNCTION-TRAMPOLINE
 121      0   0.0   1000 100.0   1000 100.0        -  "foreign function call_into_lisp"
 122      0   0.0   1000 100.0   1000 100.0        -  "foreign function new_thread_trampoline"
 123      0   0.0    970  97.0   1000 100.0        -  SB-C::COMPILE-COMPONENT
 124      0   0.0    499  49.9   1000 100.0        -  SB-C::IR1-PHASES
 125      0   0.0    460  46.0   1000 100.0        -  SB-C::%COMPILE-COMPONENT
 126      0   0.0    394  39.4   1000 100.0        -  SB-C::CONSTRAINT-PROPAGATE
 127      0   0.0    381  38.1   1000 100.0        -  SB-C::ADD-GLOBAL-CONFLICT
 128      0   0.0    381  38.1   1000 100.0        -  SB-C::LIFETIME-ANALYZE
 129      0   0.0    380  38.0   1000 100.0        -  SB-C::SETUP-ENVIRONMENT-TN-CONFLICT
 130      0   0.0    380  38.0   1000 100.0        -  SB-C::SETUP-ENVIRONMENT-TN-CONFLICTS
 131      0   0.0    378  37.8   1000 100.0        -  SB-C::FIND-AND-PROPAGATE-CONSTRAINTS
 132      0   0.0    338  33.8   1000 100.0        -  SB-C::SETUP-ENVIRONMENT-LIVE-CONFLICTS
 133      0   0.0    144  14.4   1000 100.0        -  SB-C::COMPUTE-BLOCK-IN
 134      0   0.0    114  11.4   1000 100.0        -  SB-C::UPDATE-BLOCK-IN
 135      0   0.0     96   9.6   1000 100.0        -  SB-C::IR1-OPTIMIZE
 136      0   0.0     96   9.6   1000 100.0        -  SB-C::IR1-OPTIMIZE-UNTIL-DONE
 137      0   0.0     94   9.4   1000 100.0        -  SB-C::IR1-OPTIMIZE-BLOCK
 138      0   0.0     90   9.0   1000 100.0        -  SB-C::IR1-CONVERT-LAMBDA-BODY
 139      0   0.0     87   8.7   1000 100.0        -  SB-C::IR1-CONVERT
 140      0   0.0     87   8.7   1000 100.0        -  SB-C::IR1-CONVERT-LAMBDA
 141      0   0.0     85   8.5   1000 100.0        -  SB-C::IR1-CONVERT-AUX-BINDINGS
 142      0   0.0     85   8.5   1000 100.0        -  SB-C::IR1-CONVERT-SPECIAL-BINDINGS
 143      0   0.0     85   8.5   1000 100.0        -  SB-C::IR1-CONVERT-PROGN-BODY
 144      0   0.0     85   8.5   1000 100.0        -  SB-C::IR1-OPTIMIZE-COMBINATION
 145      0   0.0     79   7.9   1000 100.0        -  SB-C::IR1-CONVERT-LET
 146      0   0.0     77   7.7   1000 100.0        -  SB-C::%PROCESSING-DECLS
 147      0   0.0     77   7.7   1000 100.0        -  SB-C::IR1-CONVERT-GLOBAL-FUNCTOID
 148      0   0.0     76   7.6   1000 100.0        -  SB-C::IR1-TRANSFORM
 149      0   0.0     75   7.5   1000 100.0        -  SB-C::%WITH-IR1-ENVIRONMENT-FROM-NODE
 150      0   0.0     73   7.3   1000 100.0        -  (LAMBDA (SB-C::NEXT SB-C::RESULT SB-C::POST-BINDING-LEXENV) :IN SB-C::IR1-CONVERT-LET)
 151      0   0.0     67   6.7   1000 100.0        -  SB-C::TRANSFORM-CALL
 152      0   0.0     66   6.6   1000 100.0        -  (FLET SB-C::CLOSURE-NEEDING-IR1-ENVIRONMENT-FROM-NODE :IN SB-C::TRANSFORM-CALL)
 153      0   0.0     65   6.5   1000 100.0        -  SB-C::IR1-CONVERT-COMBINATION-CHECKING-TYPE
 154      0   0.0     65   6.5   1000 100.0        -  SB-C::IR1-CONVERT-BLOCK
 155      0   0.0     64   6.4   1000 100.0        -  SB-C::IR1-CONVERT-COMBINATION
 156      0   0.0     58   5.8   1000 100.0        -  SB-C::ADD-TEST-CONSTRAINTS
 157      0   0.0     57   5.7   1000 100.0        -  SB-C::IR1-CONVERT-COMBINATION-ARGS
 158      0   0.0     56   5.6   1000 100.0        -  SB-C::IR1-CONVERT-IF
 159      0   0.0     56   5.6   1000 100.0        -  SB-C::IR1-CONVERT-INLINE-LAMBDA
 160      0   0.0     52   5.2   1000 100.0        -  SB-C::IR1-CONVERT-PROGN
 161      0   0.0     43   4.3   1000 100.0        -  SB-C::IR1-CONVERT-MORE
 162      0   0.0     43   4.3   1000 100.0        -  SB-C::IR1-CONVERT-HAIRY-LAMBDA
 163      0   0.0     42   4.2   1000 100.0        -  SB-C::CONVERT-TO-ENVIRONMENT-TN
 164      0   0.0     42   4.2   1000 100.0        -  SB-C::CONFLICTIZE-SAVE-P-VOP
 165      0   0.0     42   4.2   1000 100.0        -  SB-C::CONFLICT-ANALYZE-1-BLOCK
 166      0   0.0     42   4.2   1000 100.0        -  SB-C::LIFETIME-POST-PASS
 167      0   0.0     38   3.8   1000 100.0        -  SB-C::IR1-CONVERT-TAGBODY
 168      0   0.0     37   3.7   1000 100.0        -  SB-C::IR1-CONVERT-FUNCTION
 169      0   0.0     35   3.5   1000 100.0        -  SB-C::FUN-NAME-LEAF
 170      0   0.0     33   3.3   1000 100.0        -  SB-C::CONSTRAINT-PROPAGATE-IN-BLOCK
 171      0   0.0     29   2.9   1000 100.0        -  SB-C::IR1-CONVERT-MULTIPLE-VALUE-PROG1
 172      0   0.0     29   2.9   1000 100.0        -  SB-C::IR1-CONVERT-LABELS
 173      0   0.0     29   2.9   1000 100.0        -  SB-C::MAKE-FUNCTIONAL-FROM-TOPLEVEL-LAMBDA
 174      0   0.0     28   2.8   1000 100.0        -  SB-REGALLOC:PACK
 175      0   0.0     22   2.2   1000 100.0        -  SB-C::IR2-CONVERT-BLOCK
 176      0   0.0     22   2.2   1000 100.0        -  SB-C:IR2-CONVERT
 177      0   0.0     20   2.0   1000 100.0        -  SB-INT:STRINGIFY-OBJECT
 178      0   0.0     20   2.0   1000 100.0        -  PRIN1-TO-STRING
 179      0   0.0     20   2.0   1000 100.0        -  SB-C::EMIT-VOP
 180      0   0.0     20   2.0   1000 100.0        -  SB-C::EMIT-AND-INSERT-VOP
 181      0   0.0     19   1.9   1000 100.0        -  SB-C::IR1-CONVERT-RETURN-FROM
 182      0   0.0     18   1.8   1000 100.0        -  (LABELS SB-IMPL::CHECK-IT :IN SB-KERNEL:OUTPUT-OBJECT)
 183      0   0.0     15   1.5   1000 100.0        -  (LABELS SB-IMPL::PRINT-IT :IN SB-KERNEL:OUTPUT-OBJECT)
 184      0   0.0     15   1.5   1000 100.0        -  (LABELS SB-IMPL::HANDLE-IT :IN SB-KERNEL:OUTPUT-OBJECT)
 185      0   0.0     14   1.4   1000 100.0        -  SB-C::IR1-CONVERT-THE
 186      0   0.0     13   1.3   1000 100.0        -  SB-C::CONVERT-MORE-ENTRY
 187      0   0.0     13   1.3   1000 100.0        -  SB-C::LTN-ANALYZE
 188      0   0.0     12   1.2   1000 100.0        -  SB-C::IR1-CONVERT-FLET
 189      0   0.0     12   1.2   1000 100.0        -  SB-C::IR1-CONVERT-UNWIND-PROTECT
 190      0   0.0     12   1.2   1000 100.0        -  SB-C::FIND-OR-CREATE-CONSTRAINT
 191      0   0.0     11   1.1   1000 100.0        -  SB-C::THE-IN-POLICY
 192      0   0.0     11   1.1   1000 100.0        -  SB-C::IR1-CONVERT-MULTIPLE-VALUE-CALL
 193      0   0.0     11   1.1   1000 100.0        -  SB-C::LOCALL-ANALYZE-COMPONENT
 194      0   0.0     11   1.1   1000 100.0        -  SB-C::REGISTER-CONSTRAINT
 195      0   0.0     10   1.0   1000 100.0        -  SB-C::REFERENCE-TN
 196      0   0.0      9   0.9   1000 100.0        -  SB-C::DERIVE-NODE-TYPE
 197      0   0.0      9   0.9   1000 100.0        -  SB-C::GENERATE-TYPE-CHECKS
 198      0   0.0      9   0.9   1000 100.0        -  SB-C::IR2-CONVERT-FIXED-FULL-CALL
 199      0   0.0      9   0.9   1000 100.0        -  SB-C::IR2-CONVERT-FULL-CALL
 200      0   0.0      9   0.9   1000 100.0        -  SB-C::EMIT-MOVE
 201      0   0.0      8   0.8   1000 100.0        -  SB-C::LET-CONVERT
 202      0   0.0      8   0.8   1000 100.0        -  SB-C::MAYBE-LET-CONVERT
 203      0   0.0      8   0.8   1000 100.0        -  SB-C::MAYBE-ADD-EQL-VAR-LVAR-CONSTRAINT
 204      0   0.0      8   0.8   1000 100.0        -  (FLET SB-C::CLOSURE-NEEDING-IR1-ENVIRONMENT-FROM-NODE :IN SB-C::FILTER-LVAR)
 205      0   0.0      8   0.8   1000 100.0        -  SB-C::FILTER-LVAR
 206      0   0.0      8   0.8   1000 100.0        -  SB-C::CONVERT-TYPE-CHECK
 207      0   0.0      8   0.8   1000 100.0        -  SB-C::FIND-DOMINATORS
 208      0   0.0      7   0.7   1000 100.0        -  SB-C::CAREFUL-EXPAND-MACRO
 209      0   0.0      7   0.7   1000 100.0        -  SB-C::NODE-ENDS-BLOCK
 210      0   0.0      7   0.7   1000 100.0        -  SB-C::IR1-CONVERT-VAR
 211      0   0.0      7   0.7   1000 100.0        -  SB-C::IR1-OPTIMIZE-SET
 212      0   0.0      7   0.7   1000 100.0        -  SB-C::IR1-CONVERT-LOCALLY
 213      0   0.0      6   0.6   1000 100.0        -  SB-C::REFERENCE-CONSTANT
 214      0   0.0      6   0.6   1000 100.0        -  SB-C::GENERATE-OPTIONAL-DEFAULT-ENTRY
 215      0   0.0      6   0.6   1000 100.0        -  SB-C::IR1-CONVERT-HAIRY-ARGS
 216      0   0.0      6   0.6   1000 100.0        -  SB-C::CTRAN-STARTS-BLOCK
 217      0   0.0      6   0.6   1000 100.0        -  SB-KERNEL:VALUES-TYPE-INTERSECTION
 218      0   0.0      5   0.5   1000 100.0        -  SB-C::IR1-CONVERT-FBINDINGS
 219      0   0.0      5   0.5   1000 100.0        -  (LAMBDA (SB-C::NEXT SB-C::RESULT #:LEXENV828) :IN SB-C::IR1-CONVERT-FLET)
 220      0   0.0      5   0.5   1000 100.0        -  (LABELS #:BODY-NAME-2628 :IN SB-PRETTY::CALL-LOGICAL-BLOCK-PRINTER)
 221      0   0.0      5   0.5   1000 100.0        -  (FLET #:WITH-PRETTY-STREAM2626 :IN SB-PRETTY::CALL-LOGICAL-BLOCK-PRINTER)
 222      0   0.0      5   0.5   1000 100.0        -  SB-PRETTY::CALL-LOGICAL-BLOCK-PRINTER
 223      0   0.0      5   0.5   1000 100.0        -  SB-PRETTY::PPRINT-FUN-CALL
 224      0   0.0      5   0.5   1000 100.0        -  (FLET SB-C::CLOSURE-NEEDING-IR1-ENVIRONMENT-FROM-NODE :IN SB-C::MAKE-XEP)
 225      0   0.0      5   0.5   1000 100.0        -  SB-C::REFERENCE-ENTRY-POINT
 226      0   0.0      5   0.5   1000 100.0        -  SB-C::LOCALL-ANALYZE-FUN-1
 227      0   0.0      5   0.5   1000 100.0        -  SB-THREAD::CALL-WITH-RECURSIVE-SYSTEM-LOCK/WITHOUT-GCING
 228      0   0.0      5   0.5   1000 100.0        -  (FLET #:BODY-FUN-694 :IN SB-KERNEL:%PUTHASH)
 229      0   0.0      5   0.5   1000 100.0        -  SB-KERNEL:%PUTHASH
 230      0   0.0      5   0.5   1000 100.0        -  SB-INT:SSET-ADJOIN
 231      0   0.0      5   0.5   1000 100.0        -  SB-C::IR2-CONVERT-LOCAL-CALL
 232      0   0.0      5   0.5   1000 100.0        -  SB-C::IR2-OPTIMIZE
 233      0   0.0      4   0.4   1000 100.0        -  SB-C::IR1-CONVERT-TRULY-THE
 234      0   0.0      4   0.4   1000 100.0        -  SB-C::IR1-CONVERT-LET*
 235      0   0.0      4   0.4   1000 100.0        -  (FLET #:PPRINT-BLOCK :IN SB-PRETTY::PPRINT-FUN-CALL)
 236      0   0.0      4   0.4   1000 100.0        -  SB-C::IR1-CONVERT-%WITHIN-CLEANUP
 237      0   0.0      4   0.4   1000 100.0        -  SB-C::SETQ-VAR
 238      0   0.0      4   0.4   1000 100.0        -  SB-C::IR1-CONVERT-SETQ
 239      0   0.0      4   0.4   1000 100.0        -  SB-C::INSERT-LET-BODY
 240      0   0.0      4   0.4   1000 100.0        -  SB-C::IR1-CONVERT-%FUNCALL
 241      0   0.0      4   0.4   1000 100.0        -  SB-KERNEL::ARGS-TYPE-OP
 242      0   0.0      4   0.4   1000 100.0        -  SB-KERNEL::VALUES-TYPE-OP
 243      0   0.0      4   0.4   1000 100.0        -  SB-C::STACK-ANALYZE
 244      0   0.0      4   0.4   1000 100.0        -  SB-C::IR2-CONVERT-REF
 245      0   0.0      4   0.4   1000 100.0        -  SB-C:MAKE-RESTRICTED-TN
 246      0   0.0      4   0.4   1000 100.0        -  (LABELS SB-C::LINK-2BLOCKS :IN SB-C::INITIALIZE-IR2-BLOCKS-FLOW-INFO)
 247      0   0.0      4   0.4   1000 100.0        -  SB-C::INITIALIZE-IR2-BLOCKS-FLOW-INFO
 248      0   0.0      3   0.3   1000 100.0        -  SB-C::ASSERT-LVAR-TYPE
 249      0   0.0      3   0.3   1000 100.0        -  (LAMBDA (SB-C::ARG TYPE) :IN SB-C::ASSERT-CALL-TYPE)
 250      0   0.0      3   0.3   1000 100.0        -  SB-C::MAP-COMBINATION-ARGS-AND-TYPES
 251      0   0.0      3   0.3   1000 100.0        -  SB-C::ASSERT-CALL-TYPE
 252      0   0.0      3   0.3   1000 100.0        -  SB-C::VALIDATE-CALL-TYPE
 253      0   0.0      3   0.3   1000 100.0        -  SB-C::STRIP-LAMBDA-LIST
 254      0   0.0      3   0.3   1000 100.0        -  SB-C::CHECK-ARG-TYPE
 255      0   0.0      3   0.3   1000 100.0        -  SB-C::CHECK-FIXED-AND-REST
 256      0   0.0      3   0.3   1000 100.0        -  SB-C::VALID-FUN-USE
 257      0   0.0      3   0.3   1000 100.0        -  SB-KERNEL:TYPE=
 258      0   0.0      3   0.3   1000 100.0        -  SB-KERNEL:TYPE/=
 259      0   0.0      3   0.3   1000 100.0        -  SB-C::TYPE-APPROXIMATE-INTERVAL
 260      0   0.0      3   0.3   1000 100.0        -  SB-C::MOVE-RETURN-USES
 261      0   0.0      3   0.3   1000 100.0        -  SB-C::MOVE-RETURN-STUFF
 262      0   0.0      3   0.3   1000 100.0        -  SB-C::CHANGE-REF-LEAF
 263      0   0.0      3   0.3   1000 100.0        -  SB-C:MAKE-NORMAL-TN
 264      0   0.0      3   0.3   1000 100.0        -  SB-C::LTN-ANALYZE-BLOCK
 265      0   0.0      3   0.3   1000 100.0        -  SB-C:MAKE-WIRED-TN
 266      0   0.0      3   0.3   1000 100.0        -  SB-C::IR2-CONVERT-LET
 267      0   0.0      3   0.3   1000 100.0        -  SB-C::IR2-CONVERT-FULL-CALL-ARGS
 268      0   0.0      3   0.3   1000 100.0        -  SB-C::EMIT-ARG-MOVES
 269      0   0.0      3   0.3   1000 100.0        -  SB-C::EMIT-MOVES-AND-COERCIONS
 270      0   0.0      3   0.3   1000 100.0        -  SB-C::SELECT-REPRESENTATIONS
 271      0   0.0      2   0.2   1000 100.0        -  SB-C::IR1-CONVERT-QUOTE
 272      0   0.0      2   0.2   1000 100.0        -  (LABELS SB-IMPL::RECURSE :IN SB-IMPL::%MAKE-SYMBOL-NAME)
 273      0   0.0      2   0.2   1000 100.0        -  GENSYM
 274      0   0.0      2   0.2   1000 100.0        -  SB-FORMAT::%FORMATTER
 275      0   0.0      2   0.2   1000 100.0        -  (SB-C:DEFTRANSFORM FORMAT)
 276      0   0.0      2   0.2   1000 100.0        -  (FLET SB-C::CLOSURE-NEEDING-IR1-ENVIRONMENT-FROM-NODE :IN SB-C::INSERT-CAST-BEFORE)
 277      0   0.0      2   0.2   1000 100.0        -  SB-C::CONVERT-OPTIONAL-ENTRY
 278      0   0.0      2   0.2   1000 100.0        -  SB-KERNEL:VALUES-SUBTYPEP
 279      0   0.0      2   0.2   1000 100.0        -  SB-C::IR1-OPTIMIZE-CAST
 280      0   0.0      2   0.2   1000 100.0        -  (SB-C:DEFTRANSFORM <)
 281      0   0.0      2   0.2   1000 100.0        -  SB-C::DELETE-REF
 282      0   0.0      2   0.2   1000 100.0        -  SB-KERNEL::MAKE-VALUES-TYPE-CACHED
 283      0   0.0      2   0.2   1000 100.0        -  SB-KERNEL:CSUBTYPEP
 284      0   0.0      2   0.2   1000 100.0        -  SB-KERNEL::%COERCE-TO-VALUES
 285      0   0.0      2   0.2   1000 100.0        -  SB-C::CONSET-INTERSECTION
 286      0   0.0      2   0.2   1000 100.0        -  SB-KERNEL:%MAP-FOR-EFFECT-ARITY-1
 287      0   0.0      2   0.2   1000 100.0        -  SB-C::FIND-DFO
 288      0   0.0      2   0.2   1000 100.0        -  SB-C::DFO-AS-NEEDED
 289      0   0.0      2   0.2   1000 100.0        -  SB-C::LTN-ANALYZE-KNOWN-CALL
 290      0   0.0      2   0.2   1000 100.0        -  SB-C::IR2-CONVERT-TAIL-LOCAL-CALL
 291      0   0.0      2   0.2   1000 100.0        -  SB-C::COPY-PROPAGATE
 292      0   0.0      1   0.1   1000 100.0        -  PPRINT-NEWLINE
 293      0   0.0      1   0.1   1000 100.0        -  SB-IMPL::STRING-SOUT
 294      0   0.0      1   0.1   1000 100.0        -  SB-IMPL::%WRITE-STRING
 295      0   0.0      1   0.1   1000 100.0        -  (MACRO-FUNCTION DOLIST)
 296      0   0.0      1   0.1   1000 100.0        -  SB-UNICODE:NORMALIZE-STRING
 297      0   0.0      1   0.1   1000 100.0        -  SB-UNICODE:NORMALIZED-P
 298      0   0.0      1   0.1   1000 100.0        -  SB-KERNEL:OUTPUT-SYMBOL-NAME
 299      0   0.0      1   0.1   1000 100.0        -  SB-PRETTY::END-LOGICAL-BLOCK
 300      0   0.0      1   0.1   1000 100.0        -  SB-C::DEBUG-NAME
 301      0   0.0      1   0.1   1000 100.0        -  SB-C::LOCALL-ANALYZE-CLAMBDAS-UNTIL-DONE
 302      0   0.0      1   0.1   1000 100.0        -  SB-C::RECORD-COMPONENT-XREFS
 303      0   0.0      1   0.1   1000 100.0        -  SB-FORMAT::EXPAND-DIRECTIVE-LIST
 304      0   0.0      1   0.1   1000 100.0        -  SB-FORMAT::EXPAND-CONTROL-STRING
 305      0   0.0      1   0.1   1000 100.0        -  SB-C::PROPAGATE-FROM-SETS
 306      0   0.0      1   0.1   1000 100.0        -  SB-C::+-DERIVE-TYPE-AUX
 307      0   0.0      1   0.1   1000 100.0        -  SB-C::TWO-ARG-DERIVE-TYPE
 308      0   0.0      1   0.1   1000 100.0        -  SB-INT:MAKE-LAMBDA-LIST
 309      0   0.0      1   0.1   1000 100.0        -  SB-C::SSET-UNION
 310      0   0.0      1   0.1   1000 100.0        -  SB-C::MERGE-LETS
 311      0   0.0      1   0.1   1000 100.0        -  (SB-C:DEFTRANSFORM >=)
 312      0   0.0      1   0.1   1000 100.0        -  SB-C::CHANGE-BLOCK-SUCCESSOR
 313      0   0.0      1   0.1   1000 100.0        -  SB-C::UNLINK-NODE
 314      0   0.0      1   0.1   1000 100.0        -  SB-C::ENSURE-BLOCK-START
 315      0   0.0      1   0.1   1000 100.0        -  SB-C::DELETE-BLOCK
 316      0   0.0      1   0.1   1000 100.0        -  SB-C::CLEAN-COMPONENT
 317      0   0.0      1   0.1   1000 100.0        -  SB-C::JOIN-BLOCKS
 318      0   0.0      1   0.1   1000 100.0        -  SB-C::JOIN-SUCCESSOR-IF-POSSIBLE
 319      0   0.0      1   0.1   1000 100.0        -  SB-C::SUBSTITUTE-SINGLE-USE-LVAR
 320      0   0.0      1   0.1   1000 100.0        -  (FLET SB-C::DO-1-USE :IN SB-C::MOVE-RETURN-USES)
 321      0   0.0      1   0.1   1000 100.0        -  (FLET SB-C::FROB :IN SB-C::DELETE-OPTIONAL-DISPATCH)
 322      0   0.0      1   0.1   1000 100.0        -  SB-C::DELETE-OPTIONAL-DISPATCH
 323      0   0.0      1   0.1   1000 100.0        -  SB-C::DELETE-LAMBDA
 324      0   0.0      1   0.1   1000 100.0        -  SB-C::CONVERT-CALL
 325      0   0.0      1   0.1   1000 100.0        -  SB-C::CONVERT-HAIRY-CALL
 326      0   0.0      1   0.1   1000 100.0        -  SB-C::CONVERT-CALL-IF-POSSIBLE
 327      0   0.0      1   0.1   1000 100.0        -  SB-C::PROPAGATE-FUN-CHANGE
 328      0   0.0      1   0.1   1000 100.0        -  SB-C::PROPAGATE-TO-REFS
 329      0   0.0      1   0.1   1000 100.0        -  SB-KERNEL::TYPE=-LIST
 330      0   0.0      1   0.1   1000 100.0        -  SB-KERNEL::TYPE=-ARGS
 331      0   0.0      1   0.1   1000 100.0        -  SB-C::IR1-CONVERT-%%ALLOCATE-CLOSURES
 332      0   0.0      1   0.1   1000 100.0        -  (FLET SB-C::DO-1-USE :IN SB-C::SUBSTITUTE-LVAR-USES)
 333      0   0.0      1   0.1   1000 100.0        -  SB-C::SUBSTITUTE-LVAR-USES
 334      0   0.0      1   0.1   1000 100.0        -  SB-C::DELETE-FILTER
 335      0   0.0      1   0.1   1000 100.0        -  SB-C::DELETE-CAST
 336      0   0.0      1   0.1   1000 100.0        -  SB-IMPL::EXTEND-VECTOR
 337      0   0.0      1   0.1   1000 100.0        -  VECTOR-PUSH-EXTEND
 338      0   0.0      1   0.1   1000 100.0        -  SB-IMPL::DATA-VECTOR-FROM-INITS
 339      0   0.0      1   0.1   1000 100.0        -  SB-C::CONSET-UNION
 340      0   0.0      1   0.1   1000 100.0        -  SB-C::FIND-CONSTANT
 341      0   0.0      1   0.1   1000 100.0        -  SB-C::CAST-CHECK-TYPES
 342      0   0.0      1   0.1   1000 100.0        -  SB-C::SUBSTITUTE-LEAF-IF
 343      0   0.0      1   0.1   1000 100.0        -  SB-C::ADD-COMBINATION-TEST-CONSTRAINTS
 344      0   0.0      1   0.1   1000 100.0        -  SB-C::MAKE-CAST
 345      0   0.0      1   0.1   1000 100.0        -  (FLET SB-C::ENQUEUE :IN SB-C::FIND-AND-PROPAGATE-CONSTRAINTS)
 346      0   0.0      1   0.1   1000 100.0        -  SB-C::FIND-CLEANUP-POINTS
 347      0   0.0      1   0.1   1000 100.0        -  SB-C::PHYSENV-ANALYZE
 348      0   0.0      1   0.1   1000 100.0        -  SB-C::ASSIGN-LAMBDA-VAR-TNS
 349      0   0.0      1   0.1   1000 100.0        -  SB-C::GTN-ANALYZE
 350      0   0.0      1   0.1   1000 100.0        -  "foreign function interrupt_handle_pending"
 351      0   0.0      1   0.1   1000 100.0        -  "foreign function handle_trap"
 352      0   0.0      1   0.1   1000 100.0        -  SB-C::SET-TAIL-LOCAL-CALL-SUCCESSOR
 353      0   0.0      1   0.1   1000 100.0        -  SB-C::LTN-ANALYZE-LOCAL-CALL
 354      0   0.0      1   0.1   1000 100.0        -  SB-C::ANNOTATE-1-VALUE-LVAR
 355      0   0.0      1   0.1   1000 100.0        -  SB-C::FIND-LOWEST-COMMON-DOMINATOR
 356      0   0.0      1   0.1   1000 100.0        -  SB-C::BACK-PROPAGATE-ONE-DX-LVAR
 357      0   0.0      1   0.1   1000 100.0        -  SB-C::BACK-PROPAGATE-DX-LVARS
 358      0   0.0      1   0.1   1000 100.0        -  SB-C::EMIT-INITS
 359      0   0.0      1   0.1   1000 100.0        -  SB-C::IR2-CONVERT-FIXED-ALLOCATION
 360      0   0.0      1   0.1   1000 100.0        -  SB-C::FINISH-IR2-BLOCK
 361      0   0.0      1   0.1   1000 100.0        -  SB-C::EMIT-NLX-START
 362      0   0.0      1   0.1   1000 100.0        -  SB-C::MOVE-RESULTS-COERCED
 363      0   0.0      1   0.1   1000 100.0        -  SB-C::MOVE-LVAR-RESULT
 364      0   0.0      1   0.1   1000 100.0        -  SB-C::IR2-CONVERT-CONDITIONAL
 365      0   0.0      1   0.1   1000 100.0        -  SB-C::IR2-CONVERT-TEMPLATE
 366      0   0.0      1   0.1   1000 100.0        -  SB-C::INIT-COPY-SETS
 367      0   0.0      1   0.1   1000 100.0        -  SB-C::COPY-FLOW-ANALYSIS
 368      0   0.0      1   0.1   1000 100.0        -  (LABELS SB-C::MARK-2BLOCK :IN SB-C::DELETE-UNUSED-IR2-BLOCKS)
 369      0   0.0      1   0.1   1000 100.0        -  SB-C::DELETE-UNUSED-IR2-BLOCKS
 370      0   0.0      1   0.1   1000 100.0        -  SB-C::EMIT-MOVE-ARG-TEMPLATE
 371      0   0.0      1   0.1   1000 100.0        -  SB-C::CONVERT-TO-GLOBAL
 372      0   0.0      1   0.1   1000 100.0        -  SB-C::INIT-GLOBAL-CONFLICT-KIND
 373      0   0.0      1   0.1   1000 100.0        -  SB-C::LIFETIME-PRE-PASS
 374      0   0.0      1   0.1   1000 100.0        -  SB-REGALLOC::PACK-WIRED-TN
 375      0   0.0      1   0.1   1000 100.0        -  SB-REGALLOC::PACK-GREEDY
------------------------------------------------------------------------
          0   0.0                                     elsewhere

process-failure is a macro for some reason, changing it to

(defun process-failure (&rest args)
  (with-simple-restart (ignore-failure "Continue the test run.")
    (apply #'error 'check-failure args))
  (apply #'add-result 'test-failure args))

should do the trick.

Stassats' fix PR #39 seems to have worked. Thanks both of you.