Details
-
Bug
-
Resolution: Fixed
-
Medium
-
None
-
None
Description
Symptoms
When executing a webwork action on a JIRA instance on Unicorn for the first time, JIRA takes a long time, sometimes over 10 seconds to return. Execute that same action again, and it's fast. Execute another action for the first time, it's slow. Execute that same action again, it's fast. Restart JIRA, everything is slow again.
Investigation
- First thought was JSP compilation was slow due to NFS filesystem on Unicorn.
- Analysis of CPU usage showed that it tended to be CPU bound, this rules out problems due to NFS.
- Disabling JVM debug mode markedly improved performance, but the first page load was still noticeably slower (0.5s).
- Repeated thread dumps while waiting for the request to return indicated that much of the time was spent doing reflected method calls on WebworkModuleDescriptor.getImpl() by MultiTenantModuleDescriptorFactory.LifecycleInterceptor.TenantInterceptor.intercept()
- This was mostly triggered by the ActionFactory looking up the action or the view
- It was also triggered by a number of WebWork tags executing, including the if tag
- Looking at the code, WebworkModuleDescriptor.getImpl() was not just being executed to look up actions, but was also being executed to look up any webwork property. Each module descriptor is searched, in spite of the fact that it is impossible that any one of them would know the value. The way that webwork indicates that value is not known is by throwing IllegalArgumentException.
- When the action was looked up, each module descriptor when trying to find the action would look up the action extension. This in turn would trigger each module descriptor being searched for the action extension, so there are at least n2 executions done on the module descriptors for every lookup.
Example thread dump extracts:
@400000004dbe1a9a1bb6cf7c "TP-Processor3" daemon prio=10 tid=0x82f0f000 nid=0x15d575 waiting on condition [0x7fa51000] @400000004dbe1a9a1bb6d74c java.lang.Thread.State: RUNNABLE @400000004dbe1a9a1bb6d74c at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25) @400000004dbe1a9a1bb6db34 at java.lang.reflect.Method.invoke(Method.java:597) @400000004dbe1a9a1bb6df1c at com.atlassian.multitenant.plugins.MultiTenantModuleDescriptorFactory$LifecycleInterceptor$TenantInterceptor.intercept(MultiTenantModuleDescriptorFactory.java:334) @400000004dbe1a9a1bb6e6ec at com.atlassian.jira.plugin.webwork.WebworkModuleDescriptor$$EnhancerByCGLIB$$382fe89f.getImpl(<generated>) @400000004dbe1a9a1bb6eebc at webwork.config.DelegatingConfiguration.getImpl(DelegatingConfiguration.java:50) @400000004dbe1a9a1bb6eebc at com.atlassian.jira.config.webwork.JiraPluginsConfiguration.getImpl(JiraPluginsConfiguration.java:39) @400000004dbe1a9a1bb6fa74 at webwork.config.DelegatingConfiguration.getImpl(DelegatingConfiguration.java:50) @400000004dbe1a9a1bb7062c at webwork.config.DefaultConfiguration.getImpl(DefaultConfiguration.java:143) @400000004dbe1a9a1bb70a14 at com.atlassian.jira.config.webwork.DelegatingConfiguration.getImpl(DelegatingConfiguration.java:29) @400000004dbe1a9a1bb70dfc at webwork.config.Configuration.get(Configuration.java:44) @400000004dbe1a9a1bb711e4 at webwork.config.util.XMLConfigurationReader.replaceExtension(XMLConfigurationReader.java:264) @400000004dbe1a9a1bb738f4 at webwork.config.util.XMLConfigurationReader.getActionMapping(XMLConfigurationReader.java:50) @400000004dbe1a9a1bb73cdc at com.atlassian.jira.plugin.webwork.WebworkModuleDescriptor.getImpl(WebworkModuleDescriptor.java:99) @400000004dbe1a9a1bb740c4 at sun.reflect.GeneratedMethodAccessor108.invoke(Unknown Source) @400000004dbe1a9a1bb744ac at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25) @400000004dbe1a9a1bb74c7c at java.lang.reflect.Method.invoke(Method.java:597) @400000004dbe1a9a1bb74c7c at com.atlassian.multitenant.plugins.MultiTenantModuleDescriptorFactory$LifecycleInterceptor$TenantInterceptor.intercept(MultiTenantModuleDescriptorFactory.java:334) @400000004dbe1a9a1bb7544c at com.atlassian.jira.plugin.webwork.WebworkModuleDescriptor$$EnhancerByCGLIB$$382fe89f.getImpl(<generated>) @400000004dbe1a9a1bb767d4 at webwork.config.DelegatingConfiguration.getImpl(DelegatingConfiguration.java:50) @400000004dbe1a9a1bb76bbc at com.atlassian.jira.config.webwork.JiraPluginsConfiguration.getImpl(JiraPluginsConfiguration.java:39) @400000004dbe1a9a1bb76fa4 at webwork.config.DelegatingConfiguration.getImpl(DelegatingConfiguration.java:50) @400000004dbe1a9a1bb76fa4 at webwork.config.DefaultConfiguration.getImpl(DefaultConfiguration.java:143) @400000004dbe1a9a1bb77774 at com.atlassian.jira.config.webwork.DelegatingConfiguration.getImpl(DelegatingConfiguration.java:29) @400000004dbe1a9a1bb77f44 at webwork.config.Configuration.get(Configuration.java:44) @400000004dbe1a9a1bb77f44 at webwork.util.InjectionUtils.<clinit>(InjectionUtils.java:30) @400000004dbe1a9a1bb7832c at webwork.util.ValueStack.findValue(ValueStack.java:412) @400000004dbe1a9a1bb78714 at webwork.util.SimpleTest.test(SimpleTest.java:415) @400000004dbe1a9a1bb78afc at webwork.util.ValueStack.test(ValueStack.java:157) @400000004dbe1a9a1bb78ee4 at webwork.view.taglib.IfTag.doStartTag(IfTag.java:40) @400000004dbe1a9a1bb792cc at org.apache.jsp.secure.admin.views.notifications.viewschemes_jsp._jspService(viewschemes_jsp.java:154)
@400000004dbe1ad01e011954 "TP-Processor7" daemon prio=10 tid=0x80acfc00 nid=0x15de38 runnable [0x8055a000] @400000004dbe1ad01e012cdc java.lang.Thread.State: RUNNABLE @400000004dbe1ad01e0130c4 at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25) @400000004dbe1ad01e0134ac at java.lang.reflect.Method.invoke(Method.java:597) @400000004dbe1ad01e013894 at com.atlassian.multitenant.plugins.MultiTenantModuleDescriptorFactory$LifecycleInterceptor$TenantInterceptor.intercept(MultiTenantModuleDescriptorFactory.java:334) @400000004dbe1ad01e0353a4 at com.atlassian.jira.plugin.webwork.WebworkModuleDescriptor$$EnhancerByCGLIB$$382fe89f.getImpl(<generated>) @400000004dbe1ad01e03578c at webwork.config.DelegatingConfiguration.getImpl(DelegatingConfiguration.java:50) @400000004dbe1ad01e035b74 at com.atlassian.jira.config.webwork.JiraPluginsConfiguration.getImpl(JiraPluginsConfiguration.java:39) @400000004dbe1ad01e03672c at webwork.config.DelegatingConfiguration.getImpl(DelegatingConfiguration.java:50) @400000004dbe1ad01e036b14 at webwork.config.DefaultConfiguration.getImpl(DefaultConfiguration.java:143) @400000004dbe1ad01e036efc at com.atlassian.jira.config.webwork.DelegatingConfiguration.getImpl(DelegatingConfiguration.java:29) @400000004dbe1ad01e0372e4 at webwork.config.Configuration.get(Configuration.java:44) @400000004dbe1ad01e038284 at webwork.config.util.XMLConfigurationReader.replaceExtension(XMLConfigurationReader.java:264) @400000004dbe1ad01e03866c at webwork.config.util.XMLConfigurationReader.getActionMapping(XMLConfigurationReader.java:50) @400000004dbe1ad01e038a54 at com.atlassian.jira.plugin.webwork.WebworkModuleDescriptor.getImpl(WebworkModuleDescriptor.java:99) @400000004dbe1ad01e038e3c at sun.reflect.GeneratedMethodAccessor108.invoke(Unknown Source) @400000004dbe1ad01e03960c at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25) @400000004dbe1ad01e0399f4 at java.lang.reflect.Method.invoke(Method.java:597) @400000004dbe1ad01e0399f4 at com.atlassian.multitenant.plugins.MultiTenantModuleDescriptorFactory$LifecycleInterceptor$TenantInterceptor.intercept(MultiTenantModuleDescriptorFactory.java:334) @400000004dbe1ad01e03a1c4 at com.atlassian.jira.plugin.webwork.WebworkModuleDescriptor$$EnhancerByCGLIB$$382fe89f.getImpl(<generated>) @400000004dbe1ad01e03a994 at webwork.config.DelegatingConfiguration.getImpl(DelegatingConfiguration.java:50) @400000004dbe1ad01e03ad7c at com.atlassian.jira.config.webwork.JiraPluginsConfiguration.getImpl(JiraPluginsConfiguration.java:39) @400000004dbe1ad01e03b164 at webwork.config.DelegatingConfiguration.getImpl(DelegatingConfiguration.java:50) @400000004dbe1ad01e03c104 at webwork.config.DefaultConfiguration.getImpl(DefaultConfiguration.java:143) @400000004dbe1ad01e03c4ec at com.atlassian.jira.config.webwork.DelegatingConfiguration.getImpl(DelegatingConfiguration.java:29) @400000004dbe1ad01e03c8d4 at webwork.config.Configuration.get(Configuration.java:44) @400000004dbe1ad01e03ccbc at webwork.dispatcher.ConfigurationViewMapping.getView(ConfigurationViewMapping.java:57) @400000004dbe1ad01e03d48c at webwork.dispatcher.CachingViewMapping.getView(CachingViewMapping.java:43) @400000004dbe1ad01e03d48c at webwork.dispatcher.DynamicViewMapping.getView(DynamicViewMapping.java:79) @400000004dbe1ad01e03d874 at webwork.dispatcher.DefaultViewMapping.getView(DefaultViewMapping.java:33) @400000004dbe1ad01e03dc5c at webwork.dispatcher.GenericDispatcher.executeAction(GenericDispatcher.java:158) @400000004dbe1ad01e03e42c at com.atlassian.jira.web.dispatcher.JiraWebworkActionDispatcher.service(JiraWebworkActionDispatcher.java:151)
