Exponential compilation time with (DEBUG 2)

[Tobias C. Rittweiler]

This is based on FLET.20 from the ansi test suite. I encountered the
exponential behaviour because I had a PROCLAIM in my .sbclrc.

(defun test (&rest optimize-settings)
  (let ((sb-c::*policy* (sb-c::process-optimize-decl
                         `(optimize ,@optimize-settings)
                         sb-c::*policy*)))
    (handler-case
        (sb-ext:with-timeout 5
          (let* ((n (min (1- lambda-parameters-limit) 1024))
                 (vars (loop repeat n collect (gensym))))
            (eval
             `(eql ,n
                   (flet ((%f ,vars (+ ,@ vars)))
                     (%f ,@(loop for e in vars collect 1)))))))
      (sb-ext:timeout (c) c))))

CL-USER> (test)
T

CL-USER> (test '(debug 2))
;
; compilation unit aborted
; caught 1 fatal ERROR condition
#<TIMEOUT {AC880C1}>

Linux x86-32, 1.0.35.x

[Stas Boukarev (stassats)]

The current SBCL requires (debug 3) to trigger this, and this is caused by pretty-printing source forms:
https://github.com/sbcl/sbcl/blob/master/src/compiler/ir1tran.lisp#L1002

With (*print-pretty* t):

(time (test '(debug 3)))

Evaluation took:
  17.911 seconds of real time
  17.917119 seconds of total run time (17.193074 user, 0.724045 system)
  [ Run times consist of 0.172 seconds GC time, and 17.746 seconds non-GC time. ]
  100.03% CPU
  3 forms interpreted
  4 lambdas converted
  58,958,048,025 processor cycles
  2 page faults
  4,298,954,016 bytes consed

With (*print-pretty* nil):

(time (test '(debug 3)))

Evaluation took:
  1.038 seconds of real time
  1.036065 seconds of total run time (1.008063 user, 0.028002 system)
  [ Run times consist of 0.016 seconds GC time, and 1.021 seconds non-GC time. ]
  99.81% CPU
  3 forms interpreted
  4 lambdas converted
  3,417,529,794 processor cycles
  318,339,648 bytes consed

[Stas Boukarev (stassats)]

After recent changes to pprint, with (*print-pretty* t) intact (and timeouts are, of course, removed from the test-case):

(time (test '(debug 3)))
Evaluation took:
  10.046 seconds of real time
  10.040628 seconds of total run time (9.404588 user, 0.636040 system)
  [ Run times consist of 0.156 seconds GC time, and 9.885 seconds non-GC time. ]
  99.95% CPU
  3 forms interpreted
  4 lambdas converted
  33,065,221,686 processor cycles
  4,222,406,976 bytes consed

[Stas Boukarev (stassats)]

3efcbd966e9d1034e403e37985a73e53cb169cb5 should help with pretty printing.