clojure.pprint/cl-format is slow

Had a serious performance problem last week. After some digging we narrowed it down to a call to cl-format.

Some test code to demonstrate the discrepancy:

 1
 2
 3
 4
 5
 6
 7
 8
 9
10
11
12
13
14
15
16
17
18
19
20
21
22
23

;; Format a string, an integer, a conditional and fancy plural thing
(defn cl-format-test [] (clojure.pprint/cl-format nil "
    ~@[(Id: ~D)~] ~:[foo~;bar~] [~D second~:P ago]>"
                                      (java.util.UUID/randomUUID)
                                      (rand 1)
                                      (> (rand 2))
                                      (rand 100)))
;; Same inputs, just concat them and return the string
(defn str-test [] (str (java.util.UUID/randomUUID) " "
                            (rand 1) " "
                            (> (rand 2)) " "
                            (rand 100)))
;; Just format a string
(defn cl-format-simple-test [] (clojure.pprint/cl-format nil "~S" (java.util.UUID/randomUUID)))
;; Just return the string
(defn str-simple-test [] (str (java.util.UUID/randomUUID)))

(defn test-func [f tests] (time (doseq [_ (range 0 tests)] (f))))

(test-func cl-format-test 1000)
(test-func str-test 1000)
(test-func cl-format-simple-test 1000)
(test-func str-simple-test 1000)

With the following results. For the simple case, cl-format is 10 times slower than a simple string return. For more complicated format strings, closer to 100 times slower:

(test-func cl-format-test 1000)
"Elapsed time: 328.033183 msecs"
(test-func str-test 1000)
"Elapsed time: 5.939625 msecs"
(test-func cl-format-simple-test 1000)
"Elapsed time: 34.2998 msecs"
(test-func str-simple-test 1000)
"Elapsed time: 3.515013 msecs"

Having a quick look at the implementation of cl-format I immediately noticed a compile-format function which seems like something that might help out with performance for many calls to a cl-format with the same format string:

Compiles format-str into a compiled format which can be used as an argument to cl-format just like a plain format string. Use this function for improved performance when you're using the same format string repeatedly

It also seems like cl-format will check if it's format string is already compiled and skip compilation if that is the case:

(if (string? format-in) (compile-format format-in) format-in)

Oddly however, compile-format is not public, so I can't use it. So I am left a little confused. I am going to do some more digging tomorrow to solve this mystery as I am sure I am missing something here.

Not sure if pre-compilation will help solve the horrible performance you get from cl-format, but I am guessing it might help.

Update

After some discussion with my colleagues, it seems I haven't missed anything and we think this is a bug.

Permalink - Tags: Development,Clojure