[s-xml-rpc-devel] significant speed increase in SBCL

William Halliburton whalliburton at gmail.com
Sun Feb 17 01:35:19 UTC 2008


Hello all.  Using s-xml-rpc with SBCL 1.0.14 and was seeing a lot of
consing.
Just attempted to hit some low hanging fruit and got lucky.

Please excuse any wierd table cut-and-paste formatting below.

I am using hunchentoot as the front end and was calling as such:

(handle-xml-rpc-call (raw-post-data :want-stream t) id)

Profiling gave: (note that the lisp test system was calling itself so both
the call and answer are shown,
but I really only care about the answer.)

;;   seconds  |    consed   |  calls |  sec/call  |  name
;; ----------------------------------------------------------
;;     10.430 | 107,109,496 |     32 |   0.325942 | S-XML-RPC:XML-RPC-CALL
;;      5.583 |  57,897,032 |  1,670 |   0.003343 | S-XML::PARSE-IDENTIFIER
;;      1.179 |  12,740,176 |    835 |   0.001412 | S-XML::PARSE-XML-ELEMENT
;;      1.073 |   9,625,512 |  1,845 |   0.000582 | S-XML::PARSE-WHITESPACE
;;      0.988 |   8,591,704 |    239 |   0.004132 | S-XML::PARSE-TEXT
;;      0.425 |   4,491,216 |    899 |   0.000472 | S-XML::SKIP-WHITESPACE
;;      0.111 |      53,968 |  1,670 |   0.000067 | S-XML:RESOLVE-IDENTIFIER
;;      0.041 |           0 | 11,810 |   0.000003 | S-XML::IDENTIFIER-CHAR-P
;;      0.028 |     516,088 |     64 |   0.000436 | S-XML-RPC::FORMAT-HEADER
;;      0.021 |         720 |  1,670 |   0.000013 |
S-XML::FIND-NAMESPACE-BINDING
;;      0.021 |           0 |  1,845 |   0.000011 | S-XML::GET-BUFFER
;;      0.013 |           0 |  1,670 |   0.000008 | S-XML:SPLIT-IDENTIFIER
;;      0.011 |           0 |    835 |   0.000013 |
S-XML-RPC::DECODE-XML-RPC-FINISH-ELEMENT


When I changed handle-xml-rpc-call to take a string as make its own stream
as such:

(handle-xml-rpc-call-string (raw-post-data) id)


(defun handle-xml-rpc-call-string (string id)
    (with-input-from-string (in string)
      (let ((call (decode-xml-rpc in)))
        (let ((result (apply *xml-rpc-call-hook*
                             (first call)
                             (rest call))))
          (encode-xml-rpc-result result))))))

I now profile:

  seconds  |   consed   |  calls |  sec/call  |  name
---------------------------------------------------------
     0.985 | 15,135,160 |     32 |   0.030786 | S-XML-RPC:XML-RPC-CALL
     0.023 |    118,296 |  1,670 |   0.000014 | S-XML:RESOLVE-IDENTIFIER
     0.021 |          0 | 11,810 |   0.000002 | S-XML::IDENTIFIER-CHAR-P
     0.019 |    769,856 |     32 |   0.000593 | RPC-HANDLER
     0.016 |    459,688 |     64 |   0.000248 | S-XML-RPC::FORMAT-HEADER
     0.013 |     11,128 |    899 |   0.000014 | S-XML::SKIP-WHITESPACE
     0.010 |     12,536 |  1,670 |   0.000006 | S-XML::PARSE-IDENTIFIER
     0.009 |          0 |  1,670 |   0.000006 | S-XML::GET-MINI-BUFFER
     0.009 |          0 |  1,670 |   0.000006 | S-XML:SPLIT-IDENTIFIER
     0.004 |          0 |      8 |   0.000498 | UPDATE-SEARCH-STRING
     0.004 |      7,944 |     32 |   0.000118 |
S-XML-RPC::ENCODE-XML-RPC-RESULT

For a 10 fold speed increase.

I just thought this might be of use to someone down the line.

Will
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <https://mailman.common-lisp.net/pipermail/s-xml-rpc-devel/attachments/20080216/fc62c605/attachment.html>


More information about the S-xml-rpc-devel mailing list