Closed pcammish closed 6 years ago
Golang logger seems to slow the rate that connections can be processed by 20x. ab
test takes 7 seconds with Ruby logger and 138 seconds with Golang logger.
ab
test on vanilla Symbiosis Jessie (using default Ruby logger):
ab -n 10000 -c 100 http://symbiosis8.test.jnguyen.uk0.bigv.io/
This is ApacheBench, Version 2.3 <$Revision: 1826891 $>
Copyright 1996 Adam Twiss, Zeus Technology Ltd, http://www.zeustech.net/
Licensed to The Apache Software Foundation, http://www.apache.org/
Benchmarking symbiosis8.test.jnguyen.uk0.bigv.io (be patient)
Completed 1000 requests
Completed 2000 requests
Completed 3000 requests
Completed 4000 requests
Completed 5000 requests
Completed 6000 requests
Completed 7000 requests
Completed 8000 requests
Completed 9000 requests
Completed 10000 requests
Finished 10000 requests
Server Software: Apache
Server Hostname: symbiosis8.test.jnguyen.uk0.bigv.io
Server Port: 80
Document Path: /
Document Length: 209 bytes
Concurrency Level: 100
Time taken for tests: 7.571 seconds
Complete requests: 10000
Failed requests: 0
Non-2xx responses: 10000
Total transferred: 3730000 bytes
HTML transferred: 2090000 bytes
Requests per second: 1320.80 [#/sec] (mean)
Time per request: 75.712 [ms] (mean)
Time per request: 0.757 [ms] (mean, across all concurrent requests)
Transfer rate: 481.11 [Kbytes/sec] received
Connection Times (ms)
min mean[+/-sd] median max
Connect: 2 6 1.8 5 17
Processing: 13 70 20.9 63 159
Waiting: 3 69 20.9 63 159
Total: 17 75 20.4 69 162
Percentage of the requests served within a certain time (ms)
50% 69
66% 78
75% 85
80% 91
90% 108
95% 117
98% 126
99% 134
100% 162 (longest request)
After installing golang logger:
$ ab -n 10000 -c 100 http://symbiosis8.test.jnguyen.uk0.bigv.io/
This is ApacheBench, Version 2.3 <$Revision: 1826891 $>
Copyright 1996 Adam Twiss, Zeus Technology Ltd, http://www.zeustech.net/
Licensed to The Apache Software Foundation, http://www.apache.org/
Benchmarking symbiosis8.test.jnguyen.uk0.bigv.io (be patient)
Completed 1000 requests
Completed 2000 requests
Completed 3000 requests
Completed 4000 requests
Completed 5000 requests
Completed 6000 requests
Completed 7000 requests
Completed 8000 requests
Completed 9000 requests
Completed 10000 requests
Finished 10000 requests
Server Software: Apache
Server Hostname: symbiosis8.test.jnguyen.uk0.bigv.io
Server Port: 80
Document Path: /
Document Length: 209 bytes
Concurrency Level: 100
Time taken for tests: 138.132 seconds
Complete requests: 10000
Failed requests: 0
Non-2xx responses: 10000
Total transferred: 3730000 bytes
HTML transferred: 2090000 bytes
Requests per second: 72.39 [#/sec] (mean)
Time per request: 1381.321 [ms] (mean)
Time per request: 13.813 [ms] (mean, across all concurrent requests)
Transfer rate: 26.37 [Kbytes/sec] received
Connection Times (ms)
min mean[+/-sd] median max
Connect: 2 4 17.7 3 1024
Processing: 2 1374 11853.6 3 135906
Waiting: 2 1374 11853.6 3 135906
Total: 4 1377 11853.6 6 135909
Percentage of the requests served within a certain time (ms)
50% 6
66% 7
75% 9
80% 17
90% 281
95% 661
98% 1026
99% 57380
100% 135909 (longest request)
I think this might be explained by the sync flag.
The ruby script logger doesn't seem to be obeying the sync flag, based on tests. When apachebench hits the golang logger I/O wait soars up. Whereas this does not happen under ruby, despite the writes being supposedly synchronous.
I think a fix might be to remove the --sync
flag from the apache template.
Under high loads with a large number of sites (and therefore large number of instances of the logger), the symbiosis-httpd-logger process stalls and fails to write logs, apparently causing Apache to stall and spin up more processes to deal with the incoming traffic.
A workaround for this seems to be to be to adjust the Apache templates for HTTP/HTTPS sites to log directly to disk, saving the extra processor time and RAM, however this means the
logs
directories won't be automatically generated (should be fixable in symbiosis-httpd-configure or elsewhere, and log files will not be owned by admin:admin (which is not a huge problem, as they are cycled automatically, and still readable by admin).