Will,
On 17 Feb 2008, at 02:35, William Halliburton wrote:
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
Thanks for trying to optimize s-xml-rpc, a 10-fold speed-increase would be nice indeed.
However, could you please specify your change/patch against the latest version of xml-rpc.lisp version 1.11 from cvs head ? That function is considerably larger. But the key point of your change would be the same. Having said that, I feel that the speed increase and/or orginal slowness has something to do with the differences between (raw-post- data :want-stream t) and (raw-post-data) rather than with the s-xml- rpc code. The stream delivered by hunchentoot is either slow or slow as used by the xml parser (char by char). This is some kind of network stream so maybe there is some logic to this.
Anyway, you could use
(with-input-from-string (in (raw-post-data)) (handle-xml-rpc-call-string in id))
to get your optimization and without touching the original code.
Still, the tip of consuming the post data all at once and then feeding it to s-xml-rpc as a string-stream still stands.
What do you think ?
Sven