Information
This is the record of the load test runs done so far
Basic Load test
- Non-distributed
- New branch code
No Format INFO: LOAD testing MEMORY ONLY cache (items=10000, accessMultiplier=100) (2007-10-29 17:56:21,852 Timer-3_org.sakaiproject.memory.test.LoadTestMemoryService,testMemoryServiceBasicLoad (90)) WARN: boolean distributed, boolean replicated not being handled yet (2007-10-29 17:56:21,852 Timer-3_org.sakaiproject.memory.impl.BasicMemoryService,newCache (202)) INFO: Completed INSERT of 10000 items into the cache in 258 ms (25.80 microsecs per operation), Cache size is now 10000 (2007-10-29 17:56:22,134 Timer-3_org.sakaiproject.memory.test.LoadTestMemoryService,runBasicLoadTest (141)) INFO: Completed REMOVAL of 10000 items from the cache in 101 ms (10.10 microsecs per operation), Cache size is now 0 (2007-10-29 17:56:22,237 Timer-3_org.sakaiproject.memory.test.LoadTestMemoryService,runBasicLoadTest (152)) INFO: Completed GET of 10000 items from the cache 100 times each (1000000 total gets) in 710 ms (0.71 microsecs per operation), Cache hits: 1000000, misses: 0 (2007-10-29 17:56:23,043 Timer-3_org.sakaiproject.memory.test.LoadTestMemoryService,runBasicLoadTest (181)) INFO: STATS: org.sakaiproject.memory.cache.MemOnly: Size: 10000 [memory:10000, disk:0], Hits: 1000000 [memory:1010000, disk:0] (100%), Misses: 0 (0%) (2007-10-29 17:56:23,146 Timer-3_org.sakaiproject.memory.test.LoadTestMemoryService,runBasicLoadTest (185)) INFO: Completed reset of the cache in 0 ms (2007-10-29 17:56:23,147 Timer-3_org.sakaiproject.memory.test.LoadTestMemoryService,runBasicLoadTest (192)) INFO: SUMMARY:: insert: 258 ms, removal: 101 ms, get: 710 ms, reset: 0 ms (2007-10-29 17:56:23,147 Timer-3_org.sakaiproject.memory.test.LoadTestMemoryService,runBasicLoadTest (194)) INFO: LOAD testing DISK ONLY cache (items=10000, accessMultiplier=100) (2007-10-29 17:56:23,147 Timer-3_org.sakaiproject.memory.test.LoadTestMemoryService,testMemoryServiceBasicLoad (93)) WARN: boolean distributed, boolean replicated not being handled yet (2007-10-29 17:56:23,148 Timer-3_org.sakaiproject.memory.impl.BasicMemoryService,newCache (202)) INFO: Completed INSERT of 10000 items into the cache in 109 ms (10.90 microsecs per operation), Cache size is now 10000 (2007-10-29 17:56:24,016 Timer-3_org.sakaiproject.memory.test.LoadTestMemoryService,runBasicLoadTest (141)) INFO: Completed REMOVAL of 10000 items from the cache in 2032 ms (203.20 microsecs per operation), Cache size is now 0 (2007-10-29 17:56:26,049 Timer-3_org.sakaiproject.memory.test.LoadTestMemoryService,runBasicLoadTest (152)) INFO: Completed GET of 10000 items from the cache 100 times each (1000000 total gets) in 87491 ms (87.49 microsecs per operation), Cache hits: 1000000, misses: 0 (2007-10-29 17:57:53,595 Timer-3_org.sakaiproject.memory.test.LoadTestMemoryService,runBasicLoadTest (181)) INFO: STATS: org.sakaiproject.memory.cache.DiskOnly: Size: 10100 [memory:1, disk:10099], Hits: 1000000 [memory:1, disk:1009999] (100%), Misses: 0 (0%) (2007-10-29 17:57:54,461 Timer-3_org.sakaiproject.memory.test.LoadTestMemoryService,runBasicLoadTest (185)) INFO: Completed reset of the cache in 3 ms (2007-10-29 17:57:54,464 Timer-3_org.sakaiproject.memory.test.LoadTestMemoryService,runBasicLoadTest (192)) INFO: SUMMARY:: insert: 109 ms, removal: 2032 ms, get: 87491 ms, reset: 3 ms (2007-10-29 17:57:54,465 Timer-3_org.sakaiproject.memory.test.LoadTestMemoryService,runBasicLoadTest (194)) INFO: LOAD testing DEFAULT (MEM + DISK) cache (items=10000, accessMultiplier=100) (2007-10-29 17:57:54,465 Timer-3_org.sakaiproject.memory.test.LoadTestMemoryService,testMemoryServiceBasicLoad (96)) WARN: boolean distributed, boolean replicated not being handled yet (2007-10-29 17:57:54,466 Timer-3_org.sakaiproject.memory.impl.BasicMemoryService,newCache (202)) INFO: Created new Cache (from default settings): org.sakaiproject.memory.cache.Default (2007-10-29 17:57:54,467 Timer-3_org.sakaiproject.memory.impl.BasicMemoryService,instantiateCache (305)) INFO: Completed INSERT of 10000 items into the cache in 83 ms (8.30 microsecs per operation), Cache size is now 10000 (2007-10-29 17:57:54,558 Timer-3_org.sakaiproject.memory.test.LoadTestMemoryService,runBasicLoadTest (141)) INFO: Completed REMOVAL of 10000 items from the cache in 79 ms (7.90 microsecs per operation), Cache size is now 0 (2007-10-29 17:57:54,638 Timer-3_org.sakaiproject.memory.test.LoadTestMemoryService,runBasicLoadTest (152)) INFO: Completed GET of 10000 items from the cache 100 times each (1000000 total gets) in 85403 ms (85.40 microsecs per operation), Cache hits: 1000000, misses: 0 (2007-10-29 17:59:20,163 Timer-3_org.sakaiproject.memory.test.LoadTestMemoryService,runBasicLoadTest (181)) INFO: STATS: org.sakaiproject.memory.cache.Default: Size: 15574 [memory:3000, disk:12574], Hits: 1000000 [memory:3474, disk:1006526] (100%), Misses: 0 (0%) (2007-10-29 17:59:20,824 Timer-3_org.sakaiproject.memory.test.LoadTestMemoryService,runBasicLoadTest (185)) INFO: Completed reset of the cache in 3 ms (2007-10-29 17:59:20,827 Timer-3_org.sakaiproject.memory.test.LoadTestMemoryService,runBasicLoadTest (192)) INFO: SUMMARY:: insert: 83 ms, removal: 79 ms, get: 85403 ms, reset: 3 ms (2007-10-29 17:59:20,827 Timer-3_org.sakaiproject.memory.test.LoadTestMemoryService,runBasicLoadTest (194))
- Current trunk
No Format INFO: LOAD testing MEMORY ONLY cache (items=10000, accessMultiplier=100) (2007-10-29 18:23:47,467 Timer-3_org.sakaiproject.memory.test.LoadTestMemoryService,testMemoryServiceBasicLoad (90)) INFO: Added Cache name [org.sakaiproject.memory.cache.MemOnly] as Cache [org.sakaiproject.memory.cache.MemOnly] Max Elements in Memory [10000] Max Elements on Disk [0] Time to Idle (seconds) [300] Time to Live (seconds) [300] Memory Store Eviction Policy [LRU] (2007-10-29 18:23:47,468 Timer-3_org.sakaiproject.memory.impl.BasicMemoryService,notifyCacheAdded (149)) INFO: Completed INSERT of 10000 items into the cache in 180 ms (18.00 microsecs per operation), Cache size is now 10000 (2007-10-29 18:23:47,658 Timer-3_org.sakaiproject.memory.test.LoadTestMemoryService,runBasicLoadTest (141)) INFO: Completed REMOVAL of 10000 items from the cache in 92 ms (9.20 microsecs per operation), Cache size is now 0 (2007-10-29 18:23:47,751 Timer-3_org.sakaiproject.memory.test.LoadTestMemoryService,runBasicLoadTest (152)) INFO: Completed GET of 10000 items from the cache 100 times each (1000000 total gets) in 577 ms (0.58 microsecs per operation), Cache hits: 1000000, misses: 0 (2007-10-29 18:23:48,416 Timer-3_org.sakaiproject.memory.test.LoadTestMemoryService,runBasicLoadTest (181)) INFO: STATS: MemCache hits:1000000 misses:0 hit%:100 (2007-10-29 18:23:48,417 Timer-3_org.sakaiproject.memory.test.LoadTestMemoryService,runBasicLoadTest (185)) INFO: Completed reset of the cache in 0 ms (2007-10-29 18:23:48,418 Timer-3_org.sakaiproject.memory.test.LoadTestMemoryService,runBasicLoadTest (192)) INFO: SUMMARY:: insert: 180 ms, removal: 92 ms, get: 577 ms, reset: 0 ms (2007-10-29 18:23:48,418 Timer-3_org.sakaiproject.memory.test.LoadTestMemoryService,runBasicLoadTest (194)) INFO: LOAD testing DISK ONLY cache (items=10000, accessMultiplier=100) (2007-10-29 18:23:48,418 Timer-3_org.sakaiproject.memory.test.LoadTestMemoryService,testMemoryServiceBasicLoad (93)) INFO: Added Cache name [org.sakaiproject.memory.cache.DiskOnly] as Cache [org.sakaiproject.memory.cache.DiskOnly] Max Elements in Memory [10000] Max Elements on Disk [0] Time to Idle (seconds) [300] Time to Live (seconds) [300] Memory Store Eviction Policy [LRU] (2007-10-29 18:23:48,419 Timer-3_org.sakaiproject.memory.impl.BasicMemoryService,notifyCacheAdded (149)) INFO: Completed INSERT of 10000 items into the cache in 34 ms (3.40 microsecs per operation), Cache size is now 10000 (2007-10-29 18:23:48,456 Timer-3_org.sakaiproject.memory.test.LoadTestMemoryService,runBasicLoadTest (141)) INFO: Completed REMOVAL of 10000 items from the cache in 17 ms (1.70 microsecs per operation), Cache size is now 0 (2007-10-29 18:23:48,475 Timer-3_org.sakaiproject.memory.test.LoadTestMemoryService,runBasicLoadTest (152)) INFO: Completed GET of 10000 items from the cache 100 times each (1000000 total gets) in 615 ms (0.62 microsecs per operation), Cache hits: 1000000, misses: 0 (2007-10-29 18:23:49,420 Timer-3_org.sakaiproject.memory.test.LoadTestMemoryService,runBasicLoadTest (181)) INFO: STATS: MemCache hits:1000000 misses:0 hit%:100 (2007-10-29 18:23:49,422 Timer-3_org.sakaiproject.memory.test.LoadTestMemoryService,runBasicLoadTest (185)) INFO: Completed reset of the cache in 0 ms (2007-10-29 18:23:49,423 Timer-3_org.sakaiproject.memory.test.LoadTestMemoryService,runBasicLoadTest (192)) INFO: SUMMARY:: insert: 34 ms, removal: 17 ms, get: 615 ms, reset: 0 ms (2007-10-29 18:23:49,423 Timer-3_org.sakaiproject.memory.test.LoadTestMemoryService,runBasicLoadTest (194)) INFO: LOAD testing DEFAULT (MEM + DISK) cache (items=10000, accessMultiplier=100) (2007-10-29 18:23:49,423 Timer-3_org.sakaiproject.memory.test.LoadTestMemoryService,testMemoryServiceBasicLoad (96)) INFO: Added Cache name [org.sakaiproject.memory.cache.Default] as Cache [org.sakaiproject.memory.cache.Default] Max Elements in Memory [10000] Max Elements on Disk [0] Time to Idle (seconds) [300] Time to Live (seconds) [300] Memory Store Eviction Policy [LRU] (2007-10-29 18:23:49,424 Timer-3_org.sakaiproject.memory.impl.BasicMemoryService,notifyCacheAdded (149)) INFO: Completed INSERT of 10000 items into the cache in 93 ms (9.30 microsecs per operation), Cache size is now 10000 (2007-10-29 18:23:49,519 Timer-3_org.sakaiproject.memory.test.LoadTestMemoryService,runBasicLoadTest (141)) INFO: Completed REMOVAL of 10000 items from the cache in 10 ms (1.00 microsecs per operation), Cache size is now 0 (2007-10-29 18:23:49,529 Timer-3_org.sakaiproject.memory.test.LoadTestMemoryService,runBasicLoadTest (152)) INFO: Completed GET of 10000 items from the cache 100 times each (1000000 total gets) in 617 ms (0.62 microsecs per operation), Cache hits: 1000000, misses: 0 (2007-10-29 18:23:50,237 Timer-3_org.sakaiproject.memory.test.LoadTestMemoryService,runBasicLoadTest (181)) INFO: STATS: MemCache hits:1000000 misses:0 hit%:100 (2007-10-29 18:23:50,239 Timer-3_org.sakaiproject.memory.test.LoadTestMemoryService,runBasicLoadTest (185)) INFO: Completed reset of the cache in 0 ms (2007-10-29 18:23:50,239 Timer-3_org.sakaiproject.memory.test.LoadTestMemoryService,runBasicLoadTest (192)) INFO: SUMMARY:: insert: 93 ms, removal: 10 ms, get: 617 ms, reset: 0 ms (2007-10-29 18:23:50,240 Timer-3_org.sakaiproject.memory.test.LoadTestMemoryService,runBasicLoadTest (194))
- 2.4.x
No Format No runs yet
- New branch code
Comparing Disk and Memory
- Running identical tests against mixed, mem only, and disk only caches.
- Summary
CACHE
INSERT
REMOVE
GET
RESET
Mixed
4300
12200
192000
20
Memory
2100
200
8000
1
Disk
4600
12200
190000
20
- Heavy loading notes
- The heavy tests are meant to specifically overrun the cache (i.e. exceed the maximum sizes)
- The key to note here is how badly this degrades the disk cache performance (it is easily 100x worse), this would indicate that we should ensure that the disk cache size is very large when using them
- The other thing to note here is that the cost of misses in a mixed cache is also quite high, it is important to tune the cache to reduce misses when working with the disk cache
- Summary
- Results
No Format INFO: Executing delayed tests for org.sakaiproject.memory.test.LoadTestMemoryService (2007-10-29 15:21:29,339 Timer-3_org.sakaiproject.testrunner.util.TestExecutor,run (205)) INFO: LOAD testing MEMORY ONLY cache (items=100000, accessMultiplier=100) (2007-10-29 15:21:29,344 Timer-3_org.sakaiproject.memory.test.LoadTestMemoryService,testMemoryServiceBasicLoad (90)) WARN: boolean distributed, boolean replicated not being handled yet (2007-10-29 15:21:29,344 Timer-3_org.sakaiproject.memory.impl.BasicMemoryService,newCache (200)) INFO: Completed INSERT of 100000 items into the cache in 2043 ms (20.43 microsecs per operation) (2007-10-29 15:21:31,406 Timer-3_org.sakaiproject.memory.test.LoadTestMemoryService,runBasicLoadTest (137)) INFO: Completed reset of the cache in 0 ms (2007-10-29 15:21:31,428 Timer-3_org.sakaiproject.memory.test.LoadTestMemoryService,runBasicLoadTest (146)) INFO: Completed REMOVAL of 100000 items from the cache in 212 ms (2.12 microsecs per operation) (2007-10-29 15:21:32,915 Timer-3_org.sakaiproject.memory.test.LoadTestMemoryService,runBasicLoadTest (161)) INFO: Completed GET of 100000 items from the cache 100 times each (10000000 total gets) in 7965 ms (0.80 microsecs per operation) (2007-10-29 15:21:42,241 Timer-3_org.sakaiproject.memory.test.LoadTestMemoryService,runBasicLoadTest (183)) INFO: SUMMARY:: insert: 2043 ms, removal: 212 ms, get: 7965 ms, reset: 0 ms (2007-10-29 15:21:42,255 Timer-3_org.sakaiproject.memory.test.LoadTestMemoryService,runBasicLoadTest (188)) INFO: LOAD testing DISK ONLY cache (items=100000, accessMultiplier=100) (2007-10-29 15:21:42,256 Timer-3_org.sakaiproject.memory.test.LoadTestMemoryService,testMemoryServiceBasicLoad (93)) WARN: boolean distributed, boolean replicated not being handled yet (2007-10-29 15:21:42,257 Timer-3_org.sakaiproject.memory.impl.BasicMemoryService,newCache (200)) INFO: Completed INSERT of 100000 items into the cache in 4557 ms (45.57 microsecs per operation) (2007-10-29 15:21:46,814 Timer-3_org.sakaiproject.memory.test.LoadTestMemoryService,runBasicLoadTest (137)) INFO: Completed reset of the cache in 18 ms (2007-10-29 15:21:47,961 Timer-3_org.sakaiproject.memory.test.LoadTestMemoryService,runBasicLoadTest (146)) INFO: Completed REMOVAL of 100000 items from the cache in 12166 ms (121.66 microsecs per operation) (2007-10-29 15:22:04,599 Timer-3_org.sakaiproject.memory.test.LoadTestMemoryService,runBasicLoadTest (161)) INFO: Completed GET of 100000 items from the cache 100 times each (10000000 total gets) in 190747 ms (19.07 microsecs per operation) (2007-10-29 15:25:19,809 Timer-3_org.sakaiproject.memory.test.LoadTestMemoryService,runBasicLoadTest (183)) INFO: SUMMARY:: insert: 4557 ms, removal: 12166 ms, get: 190747 ms, reset: 18 ms (2007-10-29 15:25:19,810 Timer-3_org.sakaiproject.memory.test.LoadTestMemoryService,runBasicLoadTest (188)) INFO: LOAD testing DEFAULT (MEM + DISK) cache (items=100000, accessMultiplier=100) (2007-10-29 15:25:21,932 Timer-3_org.sakaiproject.memory.test.LoadTestMemoryService,testMemoryServiceBasicLoad (96)) WARN: boolean distributed, boolean replicated not being handled yet (2007-10-29 15:25:21,933 Timer-3_org.sakaiproject.memory.impl.BasicMemoryService,newCache (200)) INFO: Created new Cache (from default settings): org.sakaiproject.memory.cache.Default (2007-10-29 15:25:21,935 Timer-3_org.sakaiproject.memory.impl.BasicMemoryService,instantiateCache (303)) INFO: Completed INSERT of 100000 items into the cache in 4284 ms (42.84 microsecs per operation) (2007-10-29 15:25:26,220 Timer-3_org.sakaiproject.memory.test.LoadTestMemoryService,runBasicLoadTest (137)) INFO: Completed reset of the cache in 20 ms (2007-10-29 15:25:27,342 Timer-3_org.sakaiproject.memory.test.LoadTestMemoryService,runBasicLoadTest (146)) INFO: Completed REMOVAL of 100000 items from the cache in 10330 ms (103.30 microsecs per operation) (2007-10-29 15:25:41,709 Timer-3_org.sakaiproject.memory.test.LoadTestMemoryService,runBasicLoadTest (161)) INFO: Preparing to send the mail digests for 20071029000000000]20071030000000000 (2007-10-29 15:26:07,162 Timer-2_org.sakaiproject.email.impl.BasicEmailService,sendDigests (272)) INFO: Completed GET of 100000 items from the cache 100 times each (10000000 total gets) in 191848 ms (19.18 microsecs per operation) (2007-10-29 15:28:57,352 Timer-3_org.sakaiproject.memory.test.LoadTestMemoryService,runBasicLoadTest (183)) INFO: SUMMARY:: insert: 4284 ms, removal: 10330 ms, get: 191848 ms, reset: 20 ms (2007-10-29 15:28:57,353 Timer-3_org.sakaiproject.memory.test.LoadTestMemoryService,runBasicLoadTest (188)) INFO: Heavy LOAD testing MEMORY ONLY cache (items=200000, accessMultiplier=200) (2007-10-29 15:28:57,376 Timer-3_org.sakaiproject.memory.test.LoadTestMemoryService,testMemoryServiceHeavyLoad (105)) WARN: boolean distributed, boolean replicated not being handled yet (2007-10-29 15:28:57,376 Timer-3_org.sakaiproject.memory.impl.BasicMemoryService,newCache (200)) INFO: Completed INSERT of 200000 items into the cache in 1687 ms (8.44 microsecs per operation) (2007-10-29 15:28:59,063 Timer-3_org.sakaiproject.memory.test.LoadTestMemoryService,runBasicLoadTest (137)) INFO: Completed reset of the cache in 1 ms (2007-10-29 15:28:59,082 Timer-3_org.sakaiproject.memory.test.LoadTestMemoryService,runBasicLoadTest (146)) INFO: Completed REMOVAL of 200000 items from the cache in 136 ms (0.68 microsecs per operation) (2007-10-29 15:29:01,277 Timer-3_org.sakaiproject.memory.test.LoadTestMemoryService,runBasicLoadTest (161)) INFO: Completed GET of 200000 items from the cache 200 times each (40000000 total gets) in 25398 ms (0.63 microsecs per operation) (2007-10-29 15:29:28,916 Timer-3_org.sakaiproject.memory.test.LoadTestMemoryService,runBasicLoadTest (183)) INFO: SUMMARY:: insert: 1687 ms, removal: 136 ms, get: 25398 ms, reset: 1 ms (2007-10-29 15:29:28,935 Timer-3_org.sakaiproject.memory.test.LoadTestMemoryService,runBasicLoadTest (188)) INFO: Heavy LOAD testing DISK ONLY cache (items=200000, accessMultiplier=200) (2007-10-29 15:29:28,935 Timer-3_org.sakaiproject.memory.test.LoadTestMemoryService,testMemoryServiceHeavyLoad (108)) WARN: boolean distributed, boolean replicated not being handled yet (2007-10-29 15:29:28,936 Timer-3_org.sakaiproject.memory.impl.BasicMemoryService,newCache (200)) INFO: Completed INSERT of 200000 items into the cache in 154740 ms (773.70 microsecs per operation) (2007-10-29 15:32:03,676 Timer-3_org.sakaiproject.memory.test.LoadTestMemoryService,runBasicLoadTest (137)) INFO: Completed reset of the cache in 31 ms (2007-10-29 15:35:02,216 Timer-3_org.sakaiproject.memory.test.LoadTestMemoryService,runBasicLoadTest (146)) INFO: Completed REMOVAL of 200000 items from the cache in 242311 ms (1,211.56 microsecs per operation) (2007-10-29 15:41:46,783 Timer-3_org.sakaiproject.memory.test.LoadTestMemoryService,runBasicLoadTest (161)) INFO: Completed GET of 200000 items from the cache 200 times each (40000000 total gets) in 207022 ms (5.18 microsecs per operation) (2007-10-29 15:49:42,133 Timer-3_org.sakaiproject.memory.test.LoadTestMemoryService,runBasicLoadTest (183)) INFO: SUMMARY:: insert: 154740 ms, removal: 242311 ms, get: 207022 ms, reset: 31 ms (2007-10-29 15:49:42,134 Timer-3_org.sakaiproject.memory.test.LoadTestMemoryService,runBasicLoadTest (188)) INFO: Heavy LOAD testing DEFAULT (MEM + DISK) cache (items=200000, accessMultiplier=200) (2007-10-29 15:49:42,165 Timer-3_org.sakaiproject.memory.test.LoadTestMemoryService,testMemoryServiceHeavyLoad (111)) WARN: boolean distributed, boolean replicated not being handled yet (2007-10-29 15:49:42,166 Timer-3_org.sakaiproject.memory.impl.BasicMemoryService,newCache (200)) INFO: Completed INSERT of 200000 items into the cache in 115816 ms (579.08 microsecs per operation) (2007-10-29 15:51:37,982 Timer-3_org.sakaiproject.memory.test.LoadTestMemoryService,runBasicLoadTest (137)) INFO: Completed reset of the cache in 31 ms (2007-10-29 15:55:21,598 Timer-3_org.sakaiproject.memory.test.LoadTestMemoryService,runBasicLoadTest (146)) INFO: Completed REMOVAL of 200000 items from the cache in 247134 ms (1,235.67 microsecs per operation) (2007-10-29 16:01:41,644 Timer-3_org.sakaiproject.memory.test.LoadTestMemoryService,runBasicLoadTest (161)) INFO: Completed GET of 200000 items from the cache 200 times each (40000000 total gets) in 236525 ms (5.91 microsecs per operation) (2007-10-29 16:07:05,370 Timer-3_org.sakaiproject.memory.test.LoadTestMemoryService,runBasicLoadTest (183)) INFO: SUMMARY:: insert: 115816 ms, removal: 247134 ms, get: 236525 ms, reset: 31 ms (2007-10-29 16:07:05,371 Timer-3_org.sakaiproject.memory.test.LoadTestMemoryService,runBasicLoadTest (188)) INFO: TESTING LoadTestMemoryService: Tests passed : All 4 test(s) passed (2007-10-29 16:07:05,402 Timer-3_org.sakaiproject.testrunner.utils.TestRunnerUtils,executeSpringTests (139))