Long compilation time on deeply nested constructs with (debug 3)

[eddy]

Hi all,

at work we are doing some macro-stuff that results in rather deeply nested progn's let's and company.
Such code results in very high compilation time when compiled with debug support.
For example:

CL-USER>
(progn
  (defmacro gen-nested (level)
         `(or (read)
              ,(if (= 0 level)
                   nil
                   `(gen-nested ,(1- level)))))

  (defun test (level)
    (dolist (dbg '(0 3))
      (time
       (compile
        'bug
        `(lambda () (declare (optimize (debug ,dbg)))
            (gen-nested ,level))))))

  (test 400))

Evaluation took:
  0.090 seconds of real time
  0.089890 seconds of total run time (0.077907 user, 0.011983 system)
  [ Run times consist of 0.025 seconds GC time, and 0.065 seconds non-GC time. ]
  100.00% CPU
  1 lambda converted
  304,234,186 processor cycles
  22,656,112 bytes consed

Evaluation took:
  22.075 seconds of real time
  22.057742 seconds of total run time (22.048788 user, 0.008954 system)
  [ Run times consist of 0.044 seconds GC time, and 22.014 seconds non-GC time. ]
  99.92% CPU
  2 lambdas converted
  75,015,059,835 processor cycles
  75,344,704 bytes consed

Note the difference in timings: 0.09s w/o debugging instrumentations, 22s with debugging instrumentations.

We were able to trace the problem down to the following commit:

Author: Stas Boukarev <email address hidden> 2015-02-07 18:00:35
Committer: Stas Boukarev <email address hidden> 2015-02-07 18:00:35
Parent: c12b72591adbf77d62762de23bd557dd946cc536 (Make type caches perform better.)
Branches: master, remotes/origin/master
Follows: sbcl-1.2.8
Precedes: sbcl-1.2.9

    More complete fix for listing local variables around inlined functions.

    Walk up call-lexenvs to find visible variables, not just one level.

    Fixes lp#1419205

In the function leaf-visible-to-debugger-p from the debug-dump.lisp
this commit introduces extremely non-linear amount of traversals of lexenv's inside the visible-in-call-lexenv label.
Undoing the commit fixes the compilation time issue, however associated test
:variables-surrounding-inlined-code.2 from debug.impure.lsp is failing.

It seems clear that information for leaf-visible-to-debugger-p should be somehow cached,
but we do not feel confident enough to suggest any solution.

If someone more experienced with translator structure can propose a solution sketch we can try to implement it ourselves
and provide a patch.

Best Regards,
Eduard

P.S.
Complying with the bug report rules:

[eddy@kml10 sbcl]$ sh run-sbcl.sh --version
(running SBCL from: .)
SBCL 1.3.3.145-9b09f85

[eddy@kml10 sbcl]$ uname -a
Linux **** 3.19.3-200.fc21.x86_64 #1 SMP Thu Mar 26 21:39:42 UTC 2015 x86_64 x86_64 x86_64 GNU/Linux

[eddy@kml10 sbcl]$ sh run-sbcl.sh
(running SBCL from: .)
This is SBCL 1.3.3.145-9b09f85, an implementation of ANSI Common Lisp.
More information about SBCL is available at <http://www.sbcl.org/>.

SBCL is free software, provided as is, with absolutely no warranty.
It is mostly in the public domain; some portions are provided under
BSD-style licenses. See the CREDITS and COPYING files in the
distribution for more information.
* *features*

(:64-BIT :64-BIT-REGISTERS :ALIEN-CALLBACKS :ANSI-CL :ASH-RIGHT-VOPS
 :C-STACK-IS-CONTROL-STACK :COMMON-LISP :COMPARE-AND-SWAP-VOPS
 :COMPLEX-FLOAT-VOPS :CYCLE-COUNTER :ELF :FLOAT-EQL-VOPS
 :FP-AND-PC-STANDARD-SAVE :GENCGC :IEEE-FLOATING-POINT :INLINE-CONSTANTS
 :INTEGER-EQL-VOP :INTERLEAVED-RAW-SLOTS :LARGEFILE :LINKAGE-TABLE :LINUX
 :LITTLE-ENDIAN :MEMORY-BARRIER-VOPS :MULTIPLY-HIGH-VOPS :OS-PROVIDES-BLKSIZE-T
 :OS-PROVIDES-DLADDR :OS-PROVIDES-DLOPEN :OS-PROVIDES-GETPROTOBY-R
 :OS-PROVIDES-POLL :OS-PROVIDES-PUTWC :OS-PROVIDES-SUSECONDS-T
 :PACKAGE-LOCAL-NICKNAMES :PRECISE-ARG-COUNT-ERROR :RAW-INSTANCE-INIT-VOPS
 :SB-DOC :SB-EVAL :SB-FUTEX :SB-LDB :SB-PACKAGE-LOCKS :SB-SIMD-PACK
 :SB-SOURCE-LOCATIONS :SB-TEST :SB-THREAD :SB-UNICODE :SBCL
 :STACK-ALLOCATABLE-CLOSURES :STACK-ALLOCATABLE-FIXED-OBJECTS
 :STACK-ALLOCATABLE-LISTS :STACK-ALLOCATABLE-VECTORS
 :STACK-GROWS-DOWNWARD-NOT-UPWARD :SYMBOL-INFO-VOPS :UNIX
 :UNWIND-TO-FRAME-AND-CALL-VOP :X86-64)

[eddy (eddyz87)]

Missed the hash of the commit at question:

ef3147e4644d27591973b0826467606d75a507d9

[Stas Boukarev (stassats)]

In f6eb53a67ce39fe6047a15f00158cfb7c73659f3