By john_b on

I wanted to test the Memcache and APC modules. On a lightly lightly loaded server, with Varnish, the page generation time for a single request seemed more interesting than handling numerous request per second. I measured it with Drupal Devel module.

All services were on a single dedicated Centos server, 2GB ram, Apache prefork, fcgi, PHP 2.3, Mysql 5.1, on a fairly small and light Drupal 7 site. At all times page caching and block caching were off. Varnish caching was on (and Varnish module enabled), but Varnish cache was bypassed as I was logged in. The memcache.so php extension was loaded and one instance of memcached daemon was running. Tests were done by actitvating and deactivating modules, making necessary changes to settings.php as advised in module documentation.

RESULTS:
Times in ms to generate the front page of my site, after warming up cache, and repeating test several times, values vary by about 2ms.

Tests with php extension APC loaded, (acp.shm_size = 64M):

apc extension loaded, no contributed module for caching 360
apc extension loaded, memcache module enabled and set as default cache 310
apc extension loaded, apc module enabled and set as default cache 560

Tests with php extension APC disabled:

apc not loaded, no contributed cache module 300
apc not loaded, memcache module set as default cache 260

Tests with php extension eAccelerator loaded instead of APC:

eAccelerator loaded, no contributed cache module 225
eAccelerator loaded, memcache module set as default cache 230

Tests with php extension eAccelerator loaded as well as APC:

no contributed cache module 225
memcache module set as default cache varies 217-247

Can anyone explain this? Why is the APC extension slowing down php requests?
Would you expect the results to be different if tested with multiple requests per second?

⋅ Categories: Drupal 7.x

Comments

mcfilms’s picture

mcfilms commented

Hmmm interesting. I have no idea. Maybe you should cross-post this in the APC issue cue?

A list of some of the Drupal sites I have designed and/or developed can be viewed at motioncity.com

john_b’s picture

john_b commented

It seemed only fair to test with AB. I used a different but similar Drupal 7 site on the same server (Memcache module not installed, but still with Devel enabled). There is something bad going on here with APC.... Maybe someone can suggest where the problem may be?

AB command:
./ab -n 1000 -c 20 -k -H 'Accept-Encoding: gzip,deflate' http://mysite.com:[backend port (added to bypass varnish)]/articles

SUMMARY

The results back up the results in my first post, that is that APC has little impact on preformance, but the results using APC plus the APC module are very disappointing.

APC SETTINGS USED FOR THE TEST
apc.enabled = 1
;apc.shm_segments = 12
apc.shm_size = 64M
apc.optimization = 0
apc.num_files_hint = 4096
apc.ttl = 7200
apc.user_ttl = 7200
apc.gc_ttl = 1
apc.cache_by_default = 1
;apc.filters = "+modules"
apc.mmap_file_mask = "/tmp/apc.XXXXXX"
apc.slam_defense = 0
apc.file_update_protection = 2
apc.enable_cli = 1
apc.max_file_size = 10M
apc.stat = 1
apc.write_lock = 1
apc.report_autofilter = 0
apc.include_once-override = 0
apc.rfc1867 = 1
apc.rfc1867_prefix = "upload_"
apc.rfc1867_name = "APC_UPLOAD_PROGRESS"
apc.rfc1867_freq = 0
apc.localcache = 0
apc.localcache.size = 512
apc.coredump_unmap = 0
apc.stat_ctime = 0

RESULTS
____________________________________________
TEST 1 with apc loaded, contrib module APC off

page execution from Devel 270ms
AB results:
Document Path: /articles
Document Length: 7582 bytes

Concurrency Level: 20
Time taken for tests: 23.799 seconds
Complete requests: 1000
Failed requests: 969
(Connect: 0, Receive: 0, Length: 969, Exceptions: 0)
Write errors: 0
Keep-Alive requests: 461
Total transferred: 8110027 bytes
HTML transferred: 7580064 bytes
Requests per second: 42.02 [#/sec] (mean)
Time per request: 475.977 [ms] (mean)
Time per request: 23.799 [ms] (mean, across all concurrent requests)
Transfer rate: 332.79 [Kbytes/sec] received

Connection Times (ms)
min mean[+/-sd] median max
Connect: 0 0 0.6 0 5
Processing: 43 409 718.7 196 13763
Waiting: 37 401 711.7 191 13758
Total: 43 409 718.9 196 13763

Percentage of the requests served within a certain time (ms)
50% 196
66% 298
75% 441
80% 543
90% 978
95% 1453
98% 2422
99% 3230
100% 13763 (longest request)
____________________________________
TEST 2 with apc loaded, APC module on
single page execution from Devel 850ms
(or 1000ms with eAccelerator off)
(or 750ms with settings.php as
$conf['cache_class_cache'] = 'DrupalAPCCache';
$conf['cache_class_cache_bootstrap'] = 'DrupalAPCCache';
instead of
$conf['cache_default_class'] = 'DrupalAPCCache';)
>>THIS SLOW TIME IS THE SAME WITH MODULE DISABLED BUT SET IN settings.php
AB results:
Document Path: /articles
Document Length: 7594 bytes

Concurrency Level: 20
Time taken for tests: 800.742 seconds
Complete requests: 1000
Failed requests: 781
(Connect: 0, Receive: 0, Length: 781, Exceptions: 0)
Write errors: 0
Non-2xx responses: 6
Keep-Alive requests: 0
Total transferred: 8098037 bytes
HTML transferred: 7593923 bytes
Requests per second: 1.25 [#/sec] (mean)
Time per request: 16014.832 [ms] (mean)
Time per request: 800.742 [ms] (mean, across all concurrent requests)
Transfer rate: 9.88 [Kbytes/sec] received

Connection Times (ms)
min mean[+/-sd] median max
Connect: 0 1 7.5 0 57
Processing: 4862 15923 7595.0 14855 146052
Waiting: 3460 14885 7524.9 14093 145928
Total: 4862 15924 7595.6 14856 146109

Percentage of the requests served within a certain time (ms)
50% 14856
66% 15878
75% 16911
80% 17994
90% 22452
95% 28787
98% 37057
99% 40880
100% 146109 (longest request)
_______________________________________
REPEAT TEST 2 WITH DEVEL MODULE OFF
Document Path: /articles
Document Length: 7594 bytes

Concurrency Level: 20
Time taken for tests: 349.306 seconds
Complete requests: 1000
Failed requests: 790
(Connect: 0, Receive: 0, Length: 790, Exceptions: 0)
Write errors: 0
Non-2xx responses: 44
Keep-Alive requests: 22
Total transferred: 7837153 bytes
HTML transferred: 7336787 bytes
Requests per second: 2.86 [#/sec] (mean)
Time per request: 6986.126 [ms] (mean)
Time per request: 349.306 [ms] (mean, across all concurrent requests)
Transfer rate: 21.91 [Kbytes/sec] received

Connection Times (ms)
min mean[+/-sd] median max
Connect: 0 0 0.7 0 6
Processing: 350 6726 4580.8 5909 45392
Waiting: 350 6619 4556.4 5753 45349
Total: 350 6726 4580.8 5909 45392

Percentage of the requests served within a certain time (ms)
50% 5909
66% 7445
75% 8609
80% 9457
90% 11933
95% 14286
98% 19631
99% 24418
100% 45392 (longest request)

_________________________
TEST 3 with apc not loaded
single page execution from Devel 295ms
AB results:
Document Path: /articles
Document Length: 7593 bytes

Concurrency Level: 20
Time taken for tests: 25.436 seconds
Complete requests: 1000
Failed requests: 998
(Connect: 0, Receive: 0, Length: 998, Exceptions: 0)
Write errors: 0
Keep-Alive requests: 496
Total transferred: 8137348 bytes
HTML transferred: 7604838 bytes
Requests per second: 39.31 [#/sec] (mean)
Time per request: 508.713 [ms] (mean)
Time per request: 25.436 [ms] (mean, across all concurrent requests)
Transfer rate: 312.42 [Kbytes/sec] received

Connection Times (ms)
min mean[+/-sd] median max
Connect: 0 0 0.1 0 1
Processing: 42 499 925.1 222 12130
Waiting: 9 473 849.1 217 12120
Total: 42 499 925.1 222 12130

Percentage of the requests served within a certain time (ms)
50% 222
66% 325
75% 445
80% 546
90% 1215
95% 2021
98% 2841
99% 4708
100% 12130 (longest request)

Any ideas?

Digit Professionals specialising in Drupal, WordPress & CiviCRM support for publishers in non-profit and related sectors

john_b’s picture

john_b commented

APC was not caching owing to permissions problem on tmp folder.
Maybe this long thread will warn someone else not to make the same mistake! Setting mmap_file_mask to /dev/zero and caching works.

AB results for APC vs Memcache module on my single box (described above), with cache warmed up, follow:

APC module:
Document Path: /articles
Document Length: 7601 bytes

Concurrency Level: 20
Time taken for tests: 3.754 seconds
Complete requests: 1000
Failed requests: 906
(Connect: 0, Receive: 0, Length: 906, Exceptions: 0)
Write errors: 0
Keep-Alive requests: 0
Total transferred: 8114269 bytes
HTML transferred: 7595269 bytes
Requests per second: 266.35 [#/sec] (mean)
Time per request: 75.089 [ms] (mean)
Time per request: 3.754 [ms] (mean, across all concurrent requests)
Transfer rate: 2110.59 [Kbytes/sec] received

Connection Times (ms)
min mean[+/-sd] median max
Connect: 0 0 1.1 0 16
Processing: 22 60 46.0 53 1034
Waiting: 22 59 45.6 53 1034
Total: 23 60 46.1 54 1034

Percentage of the requests served within a certain time (ms)
50% 54
66% 58
75% 61
80% 63
90% 72
95% 87
98% 139
99% 201
100% 1034 (longest request)

Memcache module (APC still loaded but module disabled)
Document Path: /articles
Document Length: 7593 bytes

Concurrency Level: 20
Time taken for tests: 4.386 seconds
Complete requests: 1000
Failed requests: 0
Write errors: 0
Keep-Alive requests: 0
Total transferred: 8112000 bytes
HTML transferred: 7593000 bytes
Requests per second: 228.00 [#/sec] (mean)
Time per request: 87.721 [ms] (mean)
Time per request: 4.386 [ms] (mean, across all concurrent requests)
Transfer rate: 1806.16 [Kbytes/sec] received

Connection Times (ms)
min mean[+/-sd] median max
Connect: 0 0 0.6 0 5
Processing: 8 78 101.6 65 2129
Waiting: 7 77 101.6 65 2129
Total: 10 78 101.6 65 2129

Percentage of the requests served within a certain time (ms)
50% 65
66% 71
75% 76
80% 79
90% 91
95% 114
98% 221
99% 431
100% 2129 (longest request)

CONCLUSION for my type of installation results from Memcache were slightly less fast than APC cache module, and much more variable. Repeating AB test also gives less predictable speeds from Memcache.

Digit Professionals specialising in Drupal, WordPress & CiviCRM support for publishers in non-profit and related sectors

R.Muilwijk’s picture

R.Muilwijk commented

You have alot of failed requests in your APC test.. might want to look into that.