[hunchentoot-devel] serious H'toot performance problem on CCL OSX ?
JTK
jetmonk at gmail.com
Thu Aug 19 21:59:00 UTC 2010
On Aug 19, 2010, at 8:03 AM, Wade Humeniuk wrote:
> I am not seeing it Hunchentoot 1.1.0 (2010-01-08) OS X 10.6.4 ...
[Summary: Wade is getting 500+ req/sec for both 1 and 2 connections
for 64 bit CCL 1.5 on OS X]
Thank you for looking into it, Wade (and Hans, Andrey, and Robert)
Following Hans' suggestion I upgraded to CCL 1.5. I tried using both release and trunk.
This helped a bit; 2 concurrent requests now work.
To be safe, I rebuilt all of H'toot from the bknr SVN tree, just in case I missed anything the first time.
I'm running on the latest i7 Macbook Pro, so I think I should be getting speeds near the top of Wade's
range. From tcsh 'limit', my descriptors limit is 4864 and maxproc is 256
Some tests, with abbreviated outputs, are appended below, as is my dumb-server.lisp code
for comparison.
First, the conclusions:
* Replacing CCL 1.4 with 1.5 allows concurrency to work in H'toot better but not very well.
concurrency=2 works, but not 10.
* H'toot is running 4x to 10x slower for me than for Wade, yet we're both using 64 bit CCL 1.5
with Darwin Kernel Version 10.4.0, Apache Bench 2.3. I tried both the release CCL 1.5 and
the latest trunk.
* My dumb server with bordeaux threads and usocket is running at 1200 req/sec, 10x faster than
my H'toot and 2x Wade's H'toot speed. The dumb server works at a concurrency of 10,
unlike H'toot.
* My dumb server using raw CCL sockets and threads runs about as fast as the bordeaux+usocket version, so
bordeaux and usocket seem fine.
Wade, could I ask one more favor, even though you've already helped a lot? Could you please
run my (do-dumb-server-loop :port 4001) and benchmark it on your Mac? I'm curious if it
will be 5x faster on yours, like H'toot was. I'm getting about 1200 requests/sec.
Thanks,
John
;; ######################
;; run H'toot /yo page as before with 1 connection
$ ab -n 500 -c 1 http://127.0.0.1:4000/yo
Requests per second: 136.94 [#/sec] (mean) <= #### 4x slower than Wade #####
Time per request: 7.303 [ms] (mean)
Time per request: 7.303 [ms] (mean, across all concurrent requests)
Transfer rate: 22.60 [Kbytes/sec] received
;; run H'toot with 2 connections
$ ab -n 500 -c 2 http://127.0.0.1:4000/yo
Requests per second: 46.11 [#/sec] (mean) <= #### 20x slower than Wade #####
Time per request: 43.379 [ms] (mean)
Time per request: 21.689 [ms] (mean, across all concurrent requests)
Transfer rate: 7.61 [Kbytes/sec] received
;; run H'toot with 10 connections - FAILS
$ ab -n 500 -c 10 http://127.0.0.1:4000/yo
Benchmarking 127.0.0.1 (be patient)
Completed 100 requests
Completed 200 requests
Completed 300 requests
apr_socket_recv: Connection reset by peer (54)
Total of 358 requests completed
;; ######################
;; run my dumb server (see appended code) using bordeaux threads and usocket
;; this prevents more than 20 threads from running at once. It prints a warning if
;; happened, but the limit was never reached
CCL> (do-dumb-server-loop :port 4001)
;; concurrency=1
$ ab -n 500 -c 1 http://127.0.0.1:4000/yo
Concurrency Level: 1
Time taken for tests: 0.355 seconds
Complete requests: 500
Failed requests: 0
Write errors: 0
Total transferred: 47000 bytes
HTML transferred: 10500 bytes
Requests per second: 1406.64 [#/sec] (mean)
Time per request: 0.711 [ms] (mean)
Time per request: 0.711 [ms] (mean, across all concurrent requests)
Transfer rate: 129.12 [Kbytes/sec] received
;; concurrency=2
$ ab -n 500 -c 2 http://127.0.0.1:4000/yo
Concurrency Level: 2
Time taken for tests: 0.386 seconds
Complete requests: 500
Failed requests: 2
(Connect: 0, Receive: 0, Length: 2, Exceptions: 0)
Write errors: 0
Total transferred: 46812 bytes
HTML transferred: 10458 bytes
Requests per second: 1295.73 [#/sec] (mean)
Time per request: 1.544 [ms] (mean)
Time per request: 0.772 [ms] (mean, across all concurrent requests)
Transfer rate: 118.47 [Kbytes/sec] received
;; concurrency=10
$ ab -n 500 -c 10 http://127.0.0.1:4000/yo
Concurrency Level: 10
Time taken for tests: 0.483 seconds
Complete requests: 500
Failed requests: 5
(Connect: 0, Receive: 0, Length: 5, Exceptions: 0)
Write errors: 0
Total transferred: 46530 bytes
HTML transferred: 10395 bytes
Requests per second: 1034.68 [#/sec] (mean)
Time per request: 9.665 [ms] (mean)
Time per request: 0.966 [ms] (mean, across all concurrent requests)
Transfer rate: 94.03 [Kbytes/sec] received
;; now run a version of dumb server that uses native CCL threads and sockets
CCL> (do-dumb-server-loop/ccl :port 4001)
;; concurrency=1
$ ab -n 500 -c 1 http://127.0.0.1:4000/yo
oncurrency Level: 1
Time taken for tests: 0.401 seconds
Complete requests: 500
Failed requests: 0
Write errors: 0
Total transferred: 47000 bytes
HTML transferred: 10500 bytes
Requests per second: 1245.62 [#/sec] (mean) <== #### FAST #####
Time per request: 0.803 [ms] (mean)
Time per request: 0.803 [ms] (mean, across all concurrent requests)
Transfer rate: 114.34 [Kbytes/sec] received
;; concurrency=2
$ ab -n 500 -c 2 http://127.0.0.1:4000/yo
Concurrency Level: 2
Time taken for tests: 0.576 seconds
Complete requests: 500
Failed requests: 2
(Connect: 0, Receive: 0, Length: 2, Exceptions: 0)
Write errors: 0
Total transferred: 46812 bytes
HTML transferred: 10458 bytes
Requests per second: 867.85 [#/sec] (mean) <== #### FAST, but some errors #####
Time per request: 2.305 [ms] (mean)
Time per request: 1.152 [ms] (mean, across all concurrent requests)
Transfer rate: 79.35 [Kbytes/sec] received
;; concurrency=10 -
$ ab -n 500 -c 10 of http://127.0.0.1:4000/yo
Concurrency Level: 10
Time taken for tests: 0.309 seconds
Complete requests: 500
Failed requests: 2
(Connect: 0, Receive: 0, Length: 2, Exceptions: 0)
Write errors: 0
Total transferred: 46812 bytes
HTML transferred: 10458 bytes
Requests per second: 1617.78 [#/sec] (mean) <== #### FAST, but some errors #####
Time per request: 6.181 [ms] (mean)
Time per request: 0.618 [ms] (mean, across all concurrent requests)
Transfer rate: 147.91 [Kbytes/sec] received
>
> Stix:ccl wade$ uname -a
> Darwin Stix.local 10.4.0 Darwin Kernel Version 10.4.0: Fri Apr 23
> 18:28:53 PDT 2010; root:xnu-1504.7.4~1/RELEASE_I386 i386
> Stix:ccl wade$ ./dx86cl64
> ; loading system definition from
> ccl:tools;asdf-install;asdf-install.asd.newest into #<Package "ASDF0">
> ; registering #<SYSTEM ASDF-INSTALL #x3020005AD22D> as ASDF-INSTALL
> ;;; ASDF-Install version 0.6.10
> Welcome to Clozure Common Lisp Version 1.5-r13952M (DarwinX8664)!
> ? (quit)
>
> Stix:ccl wade$ ab -n 500 -c 1 http://127.0.0.1:4242/yo
> This is ApacheBench, Version 2.3 <$Revision: 655654 $>
> Copyright 1996 Adam Twiss, Zeus Technology Ltd, http://www.zeustech.net/
> Licensed to The Apache Software Foundation, http://www.apache.org/
>
> Benchmarking 127.0.0.1 (be patient)
> Completed 100 requests
> Completed 200 requests
> Completed 300 requests
> Completed 400 requests
> Completed 500 requests
> Finished 500 requests
>
>
> Server Software: Hunchentoot
> Server Hostname: 127.0.0.1
> Server Port: 4242
>
> Document Path: /yo
> Document Length: 21 bytes
>
> Concurrency Level: 1
> Time taken for tests: 0.991 seconds
> Complete requests: 500
> Failed requests: 0
> Write errors: 0
> Total transferred: 84500 bytes
> HTML transferred: 10500 bytes
> Requests per second: 504.66 [#/sec] (mean)
> Time per request: 1.982 [ms] (mean)
> Time per request: 1.982 [ms] (mean, across all concurrent requests)
> Transfer rate: 83.29 [Kbytes/sec] received
>
> Connection Times (ms)
> min mean[+/-sd] median max
> Connect: 0 0 0.0 0 0
> Processing: 1 2 1.2 2 10
> Waiting: 1 2 1.2 2 10
> Total: 1 2 1.2 2 10
>
> Percentage of the requests served within a certain time (ms)
> 50% 2
> 66% 2
> 75% 2
> 80% 2
> 90% 2
> 95% 6
> 98% 6
> 99% 6
> 100% 10 (longest request)
>
> Stix:ccl wade$ ab -n 500 -c 2 http://127.0.0.1:4242/yo
> This is ApacheBench, Version 2.3 <$Revision: 655654 $>
> Copyright 1996 Adam Twiss, Zeus Technology Ltd, http://www.zeustech.net/
> Licensed to The Apache Software Foundation, http://www.apache.org/
>
> Benchmarking 127.0.0.1 (be patient)
> Completed 100 requests
> Completed 200 requests
> Completed 300 requests
> Completed 400 requests
> Completed 500 requests
> Finished 500 requests
>
>
> Server Software: Hunchentoot
> Server Hostname: 127.0.0.1
> Server Port: 4242
>
> Document Path: /yo
> Document Length: 21 bytes
>
> Concurrency Level: 2
> Time taken for tests: 0.655 seconds
> Complete requests: 500
> Failed requests: 0
> Write errors: 0
> Total transferred: 84500 bytes
> HTML transferred: 10500 bytes
> Requests per second: 762.88 [#/sec] (mean)
> Time per request: 2.622 [ms] (mean)
> Time per request: 1.311 [ms] (mean, across all concurrent requests)
> Transfer rate: 125.91 [Kbytes/sec] received
>
> Connection Times (ms)
> min mean[+/-sd] median max
> Connect: 0 0 0.1 0 1
> Processing: 1 2 1.7 2 14
> Waiting: 0 2 1.7 2 14
> Total: 1 3 1.7 2 14
>
> Percentage of the requests served within a certain time (ms)
> 50% 2
> 66% 2
> 75% 2
> 80% 2
> 90% 6
> 95% 7
> 98% 7
> 99% 7
> 100% 14 (longest request)
> Stix:ccl wade$
>
> _______________________________________________
> tbnl-devel site list
> tbnl-devel at common-lisp.net
> http://common-lisp.net/mailman/listinfo/tbnl-devel
-------------- next part --------------
A non-text attachment was scrubbed...
Name: dumb-server.lisp
Type: application/octet-stream
Size: 3581 bytes
Desc: not available
URL: <https://mailman.common-lisp.net/pipermail/tbnl-devel/attachments/20100819/d4a04d30/attachment.obj>
-------------- next part --------------
More information about the Tbnl-devel
mailing list