1 Sep
2011
1 Sep
'11
4:41 p.m.
I ran some testing by injecting printline statements after the beginning of each
synchronization block
in all of the xwiki codebase and then ran some tests.
xwiki webstandards test:
pages loaded: 925
synchronization blocks entered: 2,512,524
synchronizations per page: 2,716
Excluding the first page load on start-up, these are the total synchronizations from
running the
webstandards tests. Note that they don't add up to exactly 2,512,524 because some were
spoiled when
2 threads tried to write to stdout simultaneously.
Total Percent Location
1651401 65.73% XWikiCacheStore.java:115
316411 12.59% EmbeddableComponentManager.java:352
142094 5.66% XWikiContext.java:260
103028 4.10% XWiki.java:5380
58151 2.31% XWikiContext.java:282
54891 2.18% XWiki.java:5455
46324 1.84% DefaultVelocityFactory.java:72
46320 1.84% DefaultVelocityFactory.java:82
29447 1.17% EmbeddableComponentManager.java:138
15010 0.60% DefaultBeanManager.java:204
14595 0.58% DefaultXWikiRenderingEngine.java:239
10933 0.44% URIClassLoader.java:438
3812 0.15% XWiki.java:5406
3262 0.13% DefaultVelocityEngine.java:227
3262 0.13% DefaultVelocityEngine.java:245
2867 0.11% XWikiNotificationManager.java:130
1941 0.08% XWikiGroupServiceImpl.java:798
958 0.04% XWikiConfigurationService.java:50
958 0.04% XWikiNotificationManager.java:254
958 0.04% XWikiNotificationManager.java:265
957 0.04% XWikiCacheStore.java:704
951 0.04% XWikiNotificationManager.java:230
949 0.04% XWikiNotificationManager.java:241
917 0.04% XWikiNotificationManager.java:219
852 0.03% XWikiStatsServiceImpl.java:182
371 0.01% XWikiDocumentQueue.java:88
351 0.01% XWikiDocumentQueue.java:55
142 0.01% XWikiDocumentQueue.java:69
112 0.00% XWikiDocumentQueue.java:98
66 0.00% AdminAction.java:57
24 0.00% RightsManager.java:164
15 0.00% EditAction.java:59
UI tests were also run to give a more well rounded view of what real traffic might look
like:
1666727 57.98% XWikiCacheStore.java:115
463369 16.12% EmbeddableComponentManager.java:352
234027 8.14% XWiki.java:5380
175972 6.12% XWikiContext.java:260
70156 2.44% XWikiContext.java:282
65952 2.29% XWiki.java:5455
43553 1.52% DefaultVelocityFactory.java:72
43552 1.52% DefaultVelocityFactory.java:82
33512 1.17% EmbeddableComponentManager.java:138
13451 0.47% DefaultBeanManager.java:204
9650 0.34% DefaultXWikiRenderingEngine.java:239
9450 0.33% XWikiNotificationManager.java:130
5176 0.18% XWikiGroupServiceImpl.java:798
5019 0.17% URIClassLoader.java:438
3965 0.14% XWiki.java:5406
2850 0.10% DefaultVelocityEngine.java:227
2850 0.10% DefaultVelocityEngine.java:245
2717 0.09% XWikiConfigurationService.java:50
2694 0.09% XWikiCacheStore.java:704
2624 0.09% XWikiNotificationManager.java:219
2624 0.09% XWikiNotificationManager.java:230
2624 0.09% XWikiNotificationManager.java:241
2590 0.09% XWikiNotificationManager.java:254
2590 0.09% XWikiNotificationManager.java:265
749 0.03% XWikiDocumentQueue.java:69
718 0.02% XWikiStatsServiceImpl.java:182
554 0.02% XWikiDocumentQueue.java:88
550 0.02% EmbeddableComponentManager.java:201
476 0.02% XWikiDocumentQueue.java:55
406 0.01% XWikiHibernateVersioningStore.java:142
403 0.01% XWikiNotificationManager.java:140
403 0.01% XWikiNotificationManager.java:155
403 0.01% XWikiNotificationManager.java:167
403 0.01% XWikiNotificationManager.java:181
403 0.01% XWikiNotificationManager.java:194
403 0.01% XWikiNotificationManager.java:206
282 0.01% XWikiDocumentQueue.java:98
209 0.01% EditAction.java:59
101 0.00% RightsManager.java:164
81 0.00% AdminAction.java:57
61 0.00% EmbeddableComponentManager.java:289
52 0.00% EmbeddableComponentManager.java:256
44 0.00% LucenePlugin.java:656
35 0.00% InlineAction.java:39
23 0.00% DefaultCSRFToken.java:130
19 0.00% MutableHttpServletRequestFactory.java:43
15 0.00% AbstractGenericComponentManager.java:93
13 0.00% LucenePlugin.java:450
5 0.00% XWikiNotificationManager.java:56
2 0.00% MacroRepository.java:65
2 0.00% XWiki.java:408
1 0.00% ActivityStreamCleaner.java:89
1 0.00% EmbeddableComponentManager.java:163
1 0.00% EmbeddableComponentManager.java:269
1 0.00% RightsManagerListener.java:85
1 0.00% SchedulerPlugin.java:561
1 0.00% StackingComponentEventManager.java:69
1 0.00% XWikiGroupServiceImpl.java:150
1 0.00% XWikiGroupServiceImpl.java:162
1 0.00% XWikiGroupServiceImpl.java:180
1 0.00% XWikiHibernateBaseStore.java:142
1 0.00% XWikiHibernateBaseStore.java:265
1 0.00% XWikiHibernateBaseStore.java:557
1 0.00% XWiki.java:5493
1 0.00% XWiki.java:5515
These numbers seem to be quite conclusive that XWikiCacheStore.java:115 is the lowest
hanging fruit
in the synchronization field. An examination of XWikiCacheStore reveals that the "per
load"
synchronization should be avoidable if it is not lazy initialized and is flushed
differently.
Is synchronization the best place to attack for performance gains?
Synchronization cost is difficult to measure because it varies based on number of
processor cores and
processor sockets. In the worst case, the caches in multiple cores on multiple processor
sockets all
need to be flushed and this would be the case with high contention mutexes.
As a matter of good practice, I think we should reduce the amount of synchronization as
much as is reasonable.
Caleb
2 Sep
2 Sep
5:08 a.m.
On 09/01/2011 10:41 AM, Caleb James DeLisle wrote:
I ran some testing by injecting printline statements
after the beginning of each synchronization block
in all of the xwiki codebase and then ran some tests.
xwiki webstandards test:
pages loaded: 925
synchronization blocks entered: 2,512,524
synchronizations per page: 2,716
Excluding the first page load on start-up, these are the total synchronizations from
running the
webstandards tests. Note that they don't add up to exactly 2,512,524 because some
were spoiled when
2 threads tried to write to stdout simultaneously.
Total Percent Location
1651401 65.73% XWikiCacheStore.java:115
316411 12.59% EmbeddableComponentManager.java:352
142094 5.66% XWikiContext.java:260
103028 4.10% XWiki.java:5380
58151 2.31% XWikiContext.java:282
54891 2.18% XWiki.java:5455
46324 1.84% DefaultVelocityFactory.java:72
46320 1.84% DefaultVelocityFactory.java:82
29447 1.17% EmbeddableComponentManager.java:138
15010 0.60% DefaultBeanManager.java:204
14595 0.58% DefaultXWikiRenderingEngine.java:239
10933 0.44% URIClassLoader.java:438
3812 0.15% XWiki.java:5406
3262 0.13% DefaultVelocityEngine.java:227
3262 0.13% DefaultVelocityEngine.java:245
2867 0.11% XWikiNotificationManager.java:130
1941 0.08% XWikiGroupServiceImpl.java:798
958 0.04% XWikiConfigurationService.java:50
958 0.04% XWikiNotificationManager.java:254
958 0.04% XWikiNotificationManager.java:265
957 0.04% XWikiCacheStore.java:704
951 0.04% XWikiNotificationManager.java:230
949 0.04% XWikiNotificationManager.java:241
917 0.04% XWikiNotificationManager.java:219
852 0.03% XWikiStatsServiceImpl.java:182
371 0.01% XWikiDocumentQueue.java:88
351 0.01% XWikiDocumentQueue.java:55
142 0.01% XWikiDocumentQueue.java:69
112 0.00% XWikiDocumentQueue.java:98
66 0.00% AdminAction.java:57
24 0.00% RightsManager.java:164
15 0.00% EditAction.java:59
UI tests were also run to give a more well rounded view of what real traffic might look
like:
1666727 57.98% XWikiCacheStore.java:115
463369 16.12% EmbeddableComponentManager.java:352
234027 8.14% XWiki.java:5380
175972 6.12% XWikiContext.java:260
70156 2.44% XWikiContext.java:282
65952 2.29% XWiki.java:5455
43553 1.52% DefaultVelocityFactory.java:72
43552 1.52% DefaultVelocityFactory.java:82
33512 1.17% EmbeddableComponentManager.java:138
13451 0.47% DefaultBeanManager.java:204
9650 0.34% DefaultXWikiRenderingEngine.java:239
9450 0.33% XWikiNotificationManager.java:130
5176 0.18% XWikiGroupServiceImpl.java:798
5019 0.17% URIClassLoader.java:438
3965 0.14% XWiki.java:5406
2850 0.10% DefaultVelocityEngine.java:227
2850 0.10% DefaultVelocityEngine.java:245
2717 0.09% XWikiConfigurationService.java:50
2694 0.09% XWikiCacheStore.java:704
2624 0.09% XWikiNotificationManager.java:219
2624 0.09% XWikiNotificationManager.java:230
2624 0.09% XWikiNotificationManager.java:241
2590 0.09% XWikiNotificationManager.java:254
2590 0.09% XWikiNotificationManager.java:265
749 0.03% XWikiDocumentQueue.java:69
718 0.02% XWikiStatsServiceImpl.java:182
554 0.02% XWikiDocumentQueue.java:88
550 0.02% EmbeddableComponentManager.java:201
476 0.02% XWikiDocumentQueue.java:55
406 0.01% XWikiHibernateVersioningStore.java:142
403 0.01% XWikiNotificationManager.java:140
403 0.01% XWikiNotificationManager.java:155
403 0.01% XWikiNotificationManager.java:167
403 0.01% XWikiNotificationManager.java:181
403 0.01% XWikiNotificationManager.java:194
403 0.01% XWikiNotificationManager.java:206
282 0.01% XWikiDocumentQueue.java:98
209 0.01% EditAction.java:59
101 0.00% RightsManager.java:164
81 0.00% AdminAction.java:57
61 0.00% EmbeddableComponentManager.java:289
52 0.00% EmbeddableComponentManager.java:256
44 0.00% LucenePlugin.java:656
35 0.00% InlineAction.java:39
23 0.00% DefaultCSRFToken.java:130
19 0.00% MutableHttpServletRequestFactory.java:43
15 0.00% AbstractGenericComponentManager.java:93
13 0.00% LucenePlugin.java:450
5 0.00% XWikiNotificationManager.java:56
2 0.00% MacroRepository.java:65
2 0.00% XWiki.java:408
1 0.00% ActivityStreamCleaner.java:89
1 0.00% EmbeddableComponentManager.java:163
1 0.00% EmbeddableComponentManager.java:269
1 0.00% RightsManagerListener.java:85
1 0.00% SchedulerPlugin.java:561
1 0.00% StackingComponentEventManager.java:69
1 0.00% XWikiGroupServiceImpl.java:150
1 0.00% XWikiGroupServiceImpl.java:162
1 0.00% XWikiGroupServiceImpl.java:180
1 0.00% XWikiHibernateBaseStore.java:142
1 0.00% XWikiHibernateBaseStore.java:265
1 0.00% XWikiHibernateBaseStore.java:557
1 0.00% XWiki.java:5493
1 0.00% XWiki.java:5515
These numbers seem to be quite conclusive that XWikiCacheStore.java:115 is the lowest
hanging fruit
in the synchronization field. An examination of XWikiCacheStore reveals that the
"per load"
synchronization should be avoidable if it is not lazy initialized and is flushed
differently.
Lazy initialization is bad. Historically, it has been done this way in
many places since the context is not available too early. This
XWikiContext class is a very bad item causing a lot of problems in the
old core.
Is synchronization the best place to attack for
performance gains?
Synchronization cost is difficult to measure because it varies based on number of
processor cores and
processor sockets. In the worst case, the caches in multiple cores on multiple processor
sockets all
need to be flushed and this would be the case with high contention mutexes.
As a matter of good practice, I think we should reduce the amount of synchronization as
much as is reasonable.
Yes, it is a valid goal to reduce as much as possible the list of
synchronized methods and blocks, and attempts in this direction have
been previously made.
IMO bad synchronization is a very good candidate for performance
improvements, since that many synchronizations for one request makes it
very likely that most of the time only one request gets to be executed,
making XWiki behave worse than a single-threaded application.
--
Sergiu Dumitriu
http://purl.org/net/sergiu/
8:58 a.m.
On Sep 2, 2011, at 5:08 AM, Sergiu Dumitriu wrote:
On 09/01/2011 10:41 AM, Caleb James DeLisle wrote:
I agree with this but IMO we should also look at improving the execution speed of a
**single** page display. When you look in the profile it's incredible how much work
we're doing that we shouldn't do (i.e. that we could do differently and faster).
For example we have 600+ SQL queries for each page load, we load the XWikiPreferences
page/object thousands of times, we do a lot of context backupping to display() object
values for the same page (when they should all use the same context), etc.
So IMO the biggest perf gain at the moment are the gains we get for improving a single
page load. That doesn't mean we shouldn't look at improve performance under stress
of course. Both should be worked on.
Thanks
-Vincent
I ran some testing by injecting printline
statements after the beginning of each synchronization block
in all of the xwiki codebase and then ran some tests.
xwiki webstandards test:
pages loaded: 925
synchronization blocks entered: 2,512,524
synchronizations per page: 2,716
Excluding the first page load on start-up, these are the total synchronizations from
running the
webstandards tests. Note that they don't add up to exactly 2,512,524 because some
were spoiled when
2 threads tried to write to stdout simultaneously.
Total Percent Location
1651401 65.73% XWikiCacheStore.java:115
316411 12.59% EmbeddableComponentManager.java:352
142094 5.66% XWikiContext.java:260
103028 4.10% XWiki.java:5380
58151 2.31% XWikiContext.java:282
54891 2.18% XWiki.java:5455
46324 1.84% DefaultVelocityFactory.java:72
46320 1.84% DefaultVelocityFactory.java:82
29447 1.17% EmbeddableComponentManager.java:138
15010 0.60% DefaultBeanManager.java:204
14595 0.58% DefaultXWikiRenderingEngine.java:239
10933 0.44% URIClassLoader.java:438
3812 0.15% XWiki.java:5406
3262 0.13% DefaultVelocityEngine.java:227
3262 0.13% DefaultVelocityEngine.java:245
2867 0.11% XWikiNotificationManager.java:130
1941 0.08% XWikiGroupServiceImpl.java:798
958 0.04% XWikiConfigurationService.java:50
958 0.04% XWikiNotificationManager.java:254
958 0.04% XWikiNotificationManager.java:265
957 0.04% XWikiCacheStore.java:704
951 0.04% XWikiNotificationManager.java:230
949 0.04% XWikiNotificationManager.java:241
917 0.04% XWikiNotificationManager.java:219
852 0.03% XWikiStatsServiceImpl.java:182
371 0.01% XWikiDocumentQueue.java:88
351 0.01% XWikiDocumentQueue.java:55
142 0.01% XWikiDocumentQueue.java:69
112 0.00% XWikiDocumentQueue.java:98
66 0.00% AdminAction.java:57
24 0.00% RightsManager.java:164
15 0.00% EditAction.java:59
UI tests were also run to give a more well rounded view of what real traffic might look
like:
1666727 57.98% XWikiCacheStore.java:115
463369 16.12% EmbeddableComponentManager.java:352
234027 8.14% XWiki.java:5380
175972 6.12% XWikiContext.java:260
70156 2.44% XWikiContext.java:282
65952 2.29% XWiki.java:5455
43553 1.52% DefaultVelocityFactory.java:72
43552 1.52% DefaultVelocityFactory.java:82
33512 1.17% EmbeddableComponentManager.java:138
13451 0.47% DefaultBeanManager.java:204
9650 0.34% DefaultXWikiRenderingEngine.java:239
9450 0.33% XWikiNotificationManager.java:130
5176 0.18% XWikiGroupServiceImpl.java:798
5019 0.17% URIClassLoader.java:438
3965 0.14% XWiki.java:5406
2850 0.10% DefaultVelocityEngine.java:227
2850 0.10% DefaultVelocityEngine.java:245
2717 0.09% XWikiConfigurationService.java:50
2694 0.09% XWikiCacheStore.java:704
2624 0.09% XWikiNotificationManager.java:219
2624 0.09% XWikiNotificationManager.java:230
2624 0.09% XWikiNotificationManager.java:241
2590 0.09% XWikiNotificationManager.java:254
2590 0.09% XWikiNotificationManager.java:265
749 0.03% XWikiDocumentQueue.java:69
718 0.02% XWikiStatsServiceImpl.java:182
554 0.02% XWikiDocumentQueue.java:88
550 0.02% EmbeddableComponentManager.java:201
476 0.02% XWikiDocumentQueue.java:55
406 0.01% XWikiHibernateVersioningStore.java:142
403 0.01% XWikiNotificationManager.java:140
403 0.01% XWikiNotificationManager.java:155
403 0.01% XWikiNotificationManager.java:167
403 0.01% XWikiNotificationManager.java:181
403 0.01% XWikiNotificationManager.java:194
403 0.01% XWikiNotificationManager.java:206
282 0.01% XWikiDocumentQueue.java:98
209 0.01% EditAction.java:59
101 0.00% RightsManager.java:164
81 0.00% AdminAction.java:57
61 0.00% EmbeddableComponentManager.java:289
52 0.00% EmbeddableComponentManager.java:256
44 0.00% LucenePlugin.java:656
35 0.00% InlineAction.java:39
23 0.00% DefaultCSRFToken.java:130
19 0.00% MutableHttpServletRequestFactory.java:43
15 0.00% AbstractGenericComponentManager.java:93
13 0.00% LucenePlugin.java:450
5 0.00% XWikiNotificationManager.java:56
2 0.00% MacroRepository.java:65
2 0.00% XWiki.java:408
1 0.00% ActivityStreamCleaner.java:89
1 0.00% EmbeddableComponentManager.java:163
1 0.00% EmbeddableComponentManager.java:269
1 0.00% RightsManagerListener.java:85
1 0.00% SchedulerPlugin.java:561
1 0.00% StackingComponentEventManager.java:69
1 0.00% XWikiGroupServiceImpl.java:150
1 0.00% XWikiGroupServiceImpl.java:162
1 0.00% XWikiGroupServiceImpl.java:180
1 0.00% XWikiHibernateBaseStore.java:142
1 0.00% XWikiHibernateBaseStore.java:265
1 0.00% XWikiHibernateBaseStore.java:557
1 0.00% XWiki.java:5493
1 0.00% XWiki.java:5515
These numbers seem to be quite conclusive that XWikiCacheStore.java:115 is the lowest
hanging fruit
in the synchronization field. An examination of XWikiCacheStore reveals that the
"per load"
synchronization should be avoidable if it is not lazy initialized and is flushed
differently.
Lazy initialization is bad. Historically, it has been done this way in
many places since the context is not available too early. This
XWikiContext class is a very bad item causing a lot of problems in the
old core.
Is synchronization the best place to attack for
performance gains?
Synchronization cost is difficult to measure because it varies based on number of
processor cores and
processor sockets. In the worst case, the caches in multiple cores on multiple processor
sockets all
need to be flushed and this would be the case with high contention mutexes.
As a matter of good practice, I think we should reduce the amount of synchronization as
much as is reasonable.
Yes, it is a valid goal to reduce as much as possible the list of
synchronized methods and blocks, and attempts in this direction have
been previously made.
IMO bad synchronization is a very good candidate for performance
improvements, since that many synchronizations for one request makes it
very likely that most of the time only one request gets to be executed,
making XWiki behave worse than a single-threaded application.
4816
days inactive
4817
days old
2 comments
3 participants
participants (3)
-
Caleb James DeLisle -
Sergiu Dumitriu -
Vincent Massol