Information
This is the record of the load test runs done so far
Basic Load test
- Non-distributed
- New branch code
INFO: Executing delayed tests for org.sakaiproject.memory.test.LoadTestMemoryService (2007-10-29 11:16:46,161 Timer-3_org.sakaiproject.testrunner.util.TestExecutor,run (205)) INFO: LOAD testing DEFAULT (MEM + DISK) cache (items=100000, accessMultiplier=100) (2007-10-29 11:16:46,166 Timer-3_org.sakaiproject.memory.test.LoadTestMemoryService,testMemoryServiceBasicLoad (84)) WARN: boolean distributed, boolean replicated not being handled yet (2007-10-29 11:16:46,166 Timer-3_org.sakaiproject.memory.impl.BasicMemoryService,newCache (196)) INFO: Created new Cache (from default settings): org.sakaiproject.memory.cache.Default (2007-10-29 11:16:46,169 Timer-3_org.sakaiproject.memory.impl.BasicMemoryService,instantiateCache (299)) INFO: Completed INSERT of 100000 items into the cache in 11880 ms (118.80 microsecs per operation) (2007-10-29 11:16:58,068 Timer-3_org.sakaiproject.memory.test.LoadTestMemoryService,runBasicLoadTest (114)) INFO: Completed reset of the cache in 18 ms (2007-10-29 11:16:58,087 Timer-3_org.sakaiproject.memory.test.LoadTestMemoryService,runBasicLoadTest (121)) INFO: Completed REMOVAL of 100000 items from the cache in 9659 ms (96.59 microsecs per operation) (2007-10-29 11:17:19,326 Timer-3_org.sakaiproject.memory.test.LoadTestMemoryService,runBasicLoadTest (135)) INFO: STATS: org.sakaiproject.memory.cache.Default: Size: 0 [memory:0, disk:0], Hits: 100000 [memory:9999, disk:90001] (100%), Misses: 0 (0%) (2007-10-29 11:17:19,346 Timer-3_org.sakaiproject.memory.test.LoadTestMemoryService,runBasicLoadTest (137)) INFO: Completed GET of 100000 items from the cache 100 times each in 22069 ms (2.21 microsecs per operation) (2007-10-29 11:17:53,236 Timer-3_org.sakaiproject.memory.test.LoadTestMemoryService,runBasicLoadTest (156)) INFO: STATS: org.sakaiproject.memory.cache.Default: Size: 100000 [memory:10000, disk:96296], Hits: 100000 [memory:3688, disk:96312] (100%), Misses: 0 (0%) (2007-10-29 11:17:53,514 Timer-3_org.sakaiproject.memory.test.LoadTestMemoryService,runBasicLoadTest (158)) INFO: LOAD testing MEMORY ONLY cache (items=100000, accessMultiplier=100) (2007-10-29 11:17:53,515 Timer-3_org.sakaiproject.memory.test.LoadTestMemoryService,testMemoryServiceBasicLoad (87)) WARN: boolean distributed, boolean replicated not being handled yet (2007-10-29 11:17:53,515 Timer-3_org.sakaiproject.memory.impl.BasicMemoryService,newCache (196)) INFO: Completed INSERT of 100000 items into the cache in 1633 ms (16.33 microsecs per operation) (2007-10-29 11:17:55,149 Timer-3_org.sakaiproject.memory.test.LoadTestMemoryService,runBasicLoadTest (114)) INFO: Completed reset of the cache in 1 ms (2007-10-29 11:17:55,150 Timer-3_org.sakaiproject.memory.test.LoadTestMemoryService,runBasicLoadTest (121)) INFO: Completed REMOVAL of 100000 items from the cache in 88 ms (0.88 microsecs per operation) (2007-10-29 11:17:56,698 Timer-3_org.sakaiproject.memory.test.LoadTestMemoryService,runBasicLoadTest (135)) INFO: STATS: org.sakaiproject.memory.cache.MemOnly: Size: 0 [memory:0, disk:0], Hits: 100000 [memory:100000, disk:0] (100%), Misses: 0 (0%) (2007-10-29 11:17:56,698 Timer-3_org.sakaiproject.memory.test.LoadTestMemoryService,runBasicLoadTest (137)) INFO: Completed GET of 100000 items from the cache 100 times each in 76 ms (0.01 microsecs per operation) (2007-10-29 11:17:58,545 Timer-3_org.sakaiproject.memory.test.LoadTestMemoryService,runBasicLoadTest (156)) INFO: STATS: org.sakaiproject.memory.cache.MemOnly: Size: 100000 [memory:100000, disk:0], Hits: 100000 [memory:100000, disk:0] (100%), Misses: 0 (0%) (2007-10-29 11:17:58,634 Timer-3_org.sakaiproject.memory.test.LoadTestMemoryService,runBasicLoadTest (158)) INFO: LOAD testing DISK ONLY cache (items=100000, accessMultiplier=100) (2007-10-29 11:17:58,634 Timer-3_org.sakaiproject.memory.test.LoadTestMemoryService,testMemoryServiceBasicLoad (90)) WARN: boolean distributed, boolean replicated not being handled yet (2007-10-29 11:17:58,635 Timer-3_org.sakaiproject.memory.impl.BasicMemoryService,newCache (196)) INFO: Completed INSERT of 100000 items into the cache in 5087 ms (50.87 microsecs per operation) (2007-10-29 11:18:03,723 Timer-3_org.sakaiproject.memory.test.LoadTestMemoryService,runBasicLoadTest (114)) INFO: Completed reset of the cache in 1120 ms (2007-10-29 11:18:04,844 Timer-3_org.sakaiproject.memory.test.LoadTestMemoryService,runBasicLoadTest (121)) INFO: Completed REMOVAL of 100000 items from the cache in 12704 ms (127.04 microsecs per operation) (2007-10-29 11:18:21,600 Timer-3_org.sakaiproject.memory.test.LoadTestMemoryService,runBasicLoadTest (135)) INFO: STATS: org.sakaiproject.memory.cache.DiskOnly: Size: 0 [memory:0, disk:0], Hits: 100000 [memory:0, disk:100000] (100%), Misses: 0 (0%) (2007-10-29 11:18:21,601 Timer-3_org.sakaiproject.memory.test.LoadTestMemoryService,runBasicLoadTest (137)) INFO: Completed GET of 100000 items from the cache 100 times each in 10052 ms (1.01 microsecs per operation) (2007-10-29 11:18:35,973 Timer-3_org.sakaiproject.memory.test.LoadTestMemoryService,runBasicLoadTest (156)) INFO: STATS: org.sakaiproject.memory.cache.DiskOnly: Size: 100000 [memory:0, disk:100759], Hits: 100000 [memory:0, disk:100000] (100%), Misses: 0 (0%) (2007-10-29 11:18:36,186 Timer-3_org.sakaiproject.memory.test.LoadTestMemoryService,runBasicLoadTest (158)) INFO: TESTING LoadTestMemoryService: Tests passed : All 3 test(s) passed (2007-10-29 11:18:36,187 Timer-3_org.sakaiproject.testrunner.utils.TestRunnerUtils,executeSpringTests (139))
- Current trunk
No runs yet
- 2.4.x
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
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))