[Openmcl-devel] Speed of concatenate vs format

[Daniel Dickison]

I've been working with some legacy code that contains many instances  
of --

	(format nil "~a~a" string1 string2)

for concatenating strings.  This code is in some code that is a  
performance bottleneck, and I thought, surely, this would be more  
efficient if rewritten as --

	(concatenate 'string string1 string2)

but this turns out not to be the case.  In fact, using format for  
string concatenation is significantly faster.  So assuming the  
overhead for parsing the format control string is negligible, the  
format version probably becomes two calls to princ wrapped in a with- 
output-to-string.  How come this is so much faster than concatenate?

Now that I've done the profiling, I know which code to use, but I'm  
still really curious why this is the case.  I would appreciate any  
insight.  Below is the results of some quick-and-dirty profiling on  
CCL Version 1.3-r11987M  (DarwinX8664), an iMac Core 2 Duo.

Thanks!

Daniel


CL-USER> (defvar *str* (make-string 2000 :initial-element #\a))
*STR*

CL-USER> (time (dotimes (i 100000)
		 (format nil "~a~a" *str* *str*)))
(DOTIMES (I 100000) (FORMAT NIL "~a~a" *STR* *STR*)) took 5,547,598  
microseconds (5.547598 seconds) to run
                     with 2 available CPU cores.
During that period, 3,288,825 microseconds (3.288825 seconds) were  
spent in user mode
                     770,732 microseconds (0.770732 seconds) were  
spent in system mode
1,076,633 microseconds (1.076633 seconds) was spent in GC.
  1,606,416,016 bytes of memory allocated.
NIL

CL-USER> (time (dotimes (i 100000)
		 (concatenate 'string *str* *str*)))
(DOTIMES (I 100000) (CONCATENATE 'STRING *STR* *STR*)) took 10,373,570  
microseconds (10.373570 seconds) to run
                     with 2 available CPU cores.
During that period, 8,092,791 microseconds (8.092791 seconds) were  
spent in user mode
                     878,887 microseconds (0.878887 seconds) were  
spent in system mode
1,097,819 microseconds (1.097819 seconds) was spent in GC.
  1,601,600,000 bytes of memory allocated.
NIL

CL-USER> (time (dotimes (i 100000)
		 (with-output-to-string (s)
		   (princ *str* s)
		   (princ *str* s))))
(DOTIMES (I 100000) (WITH-OUTPUT-TO-STRING (S) (PRINC *STR* S) (PRINC  
*STR* S))) took 5,284,978 microseconds (5.284978 seconds) to run
                     with 2 available CPU cores.
During that period, 3,153,681 microseconds (3.153681 seconds) were  
spent in user mode
                     752,712 microseconds (0.752712 seconds) were  
spent in system mode
1,087,328 microseconds (1.087328 seconds) was spent in GC.
  1,606,416,016 bytes of memory allocated.