Great work Andreas. I'm eager to see this applied.
Thanks
-Vincent
On Jun 9, 2010, at 10:38 PM, Andreas Jonsson wrote:
> Hi,
>
> I did a quick benchmarking on the right service, to see what the
> benefits of caching is. I measured the time in nano-seconds over the
> methods checkAccess and hasAccessLevel. The server is run on a
> virtual machine, so the statistics is not entirely reliable.
> I have made some interesting observations, however:
>
> * hasAccessLevel is called a large number of times per page view. It
> is called around 20 times as often as checkAccess, which should
> normally be called once per accessed wiki-document.
>
> * The main reason for the large number of calls to hasAccessLevel are
> these variable initializations in xwikivars.vm:
>
> #set($hasEdit = $xwiki.hasAccessLevel("edit"))
> #set($hasAdmin = $xwiki.hasAccessLevel("admin"))
> ## Note: In order to know if the user has the right to create a space we
> compute a space name that doesn't exist and check edit rights on that space
> #set($hasCreateSpace = $xwiki.hasAccessLevel("edit",
> "${doc.space}${mathtool.random(0,
> 999)}.DocumentReservedForInternalXWikiUsage"))
> ## Note: In order to know if the user has the right to create a page we
> compute a page name that doesn't exist and check edit rights on that page
> #set($hasCreatePage = $xwiki.hasAccessLevel("edit",
> "${doc.space}.DocumentReservedForInternalXWikiUsage${mathtool.random(0,
> 999)}"))
> #set($hasGlobalAdmin = $xwiki.hasAccessLevel("admin", $context.user,
> "XWiki.XWikiPreferences"))
> ## Note: The document name is not internally used to determine if a user
> has programming access level. We pass XWiki.XWikiPreferences for
> consistency with the call for global admin
> #set($hasProgramming = $xwiki.hasAccessLevel("programming",
> $context.user, "XWiki.XWikiPreferences"))
> #set($hasSpaceAdmin = $xwiki.hasAccessLevel("admin", $context.user,
> "${doc.space}.WebPreferences"))
>
> Due to the ugly hack with randomly generated space names and document
> names for initiating the variables "$hasCreateSpace" and
> "$hasCreatePage", the caching implementation perform worse than it
> could, as this will cause many cache misses and waste cache space.
> However, my new implementation internally operates by computing and
> caching the rights corresponding to an EntityReference, which may
> refer to a document, a space, or a wiki. If this is exposed via the
> API it will be possible to query for the rights on a space and wiki
> directly.
>
> By removing the randomness :
>
> #set($hasCreateSpace = $xwiki.hasAccessLevel("edit",
> "${doc.space}INTERNAL.DocumentReservedForInternalXWikiUsage"))
> #set($hasCreatePage = $xwiki.hasAccessLevel("edit",
> "${doc.space}.DocumentReservedForInternalXWikiUsage"))
>
> and running a test by reloading the same page over and over, we see
> the benefit of caching:
>
> Original implementation:
>
> Statistics for checkAccess:
>
> DescriptiveStatistics:
> n: 2030
> min: 522859.0
> max: 5.39733259E8
> mean: 1.7198616874876842E7
> std dev: 3.7962038152575314E7
> median: 659100.0
> skewness: 4.262358507299374
> kurtosis: 30.885271611362477
>
> Statistics for hasAccessLevel:
>
> DescriptiveStatistics:
> n: 39402
> min: 69016.0
> max: 6.40750283E8
> mean: 8595126.655296639
> std dev: 2.770284412153291E7
> median: 592985.0
> skewness: 5.682505086745415
> kurtosis: 50.72341779375682
>
> -----------------------------------------
>
> My new implementation:
>
> Statistics for checkAccess:
>
> DescriptiveStatistics:
> n: 2030
> min: 27763.0
> max: 3.01349107E8
> mean: 3118090.7699507335
> std dev: 1.6890870361759447E7
> median: 132935.0
> skewness: 8.995243673145804
> kurtosis: 105.30119067606974
>
> Statistics for hasAccessLevel:
>
> DescriptiveStatistics:
> n: 33368
> min: 26086.0
> max: 1.239094745E9
> mean: 767290.0766902551
> std dev: 1.0969784229187453E7
> median: 32915.5
> skewness: 55.482434651126056
> kurtosis: 5256.531317809735
>
> Considering the skewed nature of the distribution, the mean value
> cannot be used to predict the delay caused by the right service.
> Considering that hasAccessLevel seems to be called more than 30 times
> per page request, a naive interpretation suggests that over 200 ms was
> polished of the average request time (7.8 ms * 30). This is obviously
> bogus, since the mean request time was 170.027 ms for the original
> implementation and 144.743 ms for my new implementation.
>
> The requests were performed with 'ab -c 10 -n 1000 -k ':
>
> Output for original implementation:
>
> Server Software: Apache-Coyote/1.1
> Server Hostname: wiki
> Server Port: 8080
>
> Document Path: /xw/bin/view/Gob/WebHome
> Document Length: 0 bytes
>
> Concurrency Level: 10
> Time taken for tests: 170.027 seconds
> Complete requests: 1000
> Failed requests: 0
> Write errors: 0
> Non-2xx responses: 1000
> Keep-Alive requests: 995
> Total transferred: 414975 bytes
> HTML transferred: 0 bytes
> Requests per second: 5.88 [#/sec] (mean)
> Time per request: 1700.269 [ms] (mean)
> Time per request: 170.027 [ms] (mean, across all concurrent requests)
> Transfer rate: 2.38 [Kbytes/sec] received
>
> Connection Times (ms)
> min mean[+/-sd] median max
> Connect: 0 0 0.2 0 3
> Processing: 445 1694 412.3 1654 3663
> Waiting: 445 1694 412.3 1654 3663
> Total: 445 1694 412.4 1654 3663
>
> --------------------------------------------------------------------------------
>
> Output for my new implementation:
>
> Server Software: Apache-Coyote/1.1
> Server Hostname: wiki
> Server Port: 8080
>
> Document Path: /xw/bin/view/Gob/WebHome
> Document Length: 0 bytes
>
> Concurrency Level: 10
> Time taken for tests: 144.743 seconds
> Complete requests: 1000
> Failed requests: 0
> Write errors: 0
> Non-2xx responses: 1000
> Keep-Alive requests: 993
> Total transferred: 414965 bytes
> HTML transferred: 0 bytes
> Requests per second: 6.91 [#/sec] (mean)
> Time per request: 1447.426 [ms] (mean)
> Time per request: 144.743 [ms] (mean, across all concurrent requests)
> Transfer rate: 2.80 [Kbytes/sec] received
>
> Connection Times (ms)
> min mean[+/-sd] median max
> Connect: 0 0 0.2 0 4
> Processing: 374 1441 428.1 1415 3228
> Waiting: 374 1441 428.1 1415 3228
> Total: 374 1441 428.1 1415 3228
>
>
> My implementation needs some more testing, but I will try to upload it
> to Jira by tomorrow.
>
> Best regards,
>
> Andreas Jonsson
_______________________________________________
devs mailing list
[email protected]
http://lists.xwiki.org/mailman/listinfo/devs
