-
Bug
-
Resolution: Unresolved
-
Low
-
None
-
7.6.0, 7.6.6, 7.11.0
-
7.06
-
5
-
Severity 3 - Minor
-
0
-
Problem
JMX Monitoring is slow due to license count and delays startup.
- Related:
JRASERVER-64384- license count slow - Can Cause:
JRASERVER-67613- lock check failures
Diagnosis
In a large instance with many users and groups, JMX startup may be slow.
Application Logs
Logs may have noticeable delays like:
2018-07-13 17:55:09,844 localhost-startStop-1 INFO [c.a.j.instrumentation.external.DatabaseExternalGauges] Installing DBCP monitoring instruments: DatabaseExternalGauges.JiraDbcpInstruments[instruments=[DBCP_MAX, DBCP_ACTIVE, DBCP_IDLE],objectName=com.atlassian.jira:name=BasicDataSource] 2018-07-13 17:55:38,300 localhost-startStop-1 WARN [c.a.jira.health.HealthChecks] Your database is using an unsupported collation
- Note this 20s delay, generally this is expected to occur within a few seconds.
Thread Dumps
When taking frequent thread dumps, in this case with 2s intervals, we see this long-running thread:
"localhost-startStop-1" #29 daemon prio=5 os_prio=0 tid=0x00007f36a0001800 nid=0x4227 runnable [0x00007f3701afe000] java.lang.Thread.State: RUNNABLE at org.ofbiz.core.entity.model.ModelFieldTypeReader.getModelFieldType(ModelFieldTypeReader.java:195) at org.ofbiz.core.entity.jdbc.SqlJdbcUtil.getValue(SqlJdbcUtil.java:596) at org.ofbiz.core.entity.EntityListIterator.currentGenericValue(EntityListIterator.java:181) at org.ofbiz.core.entity.EntityListIterator.next(EntityListIterator.java:267) at com.atlassian.jira.ofbiz.DefaultOfBizListIterator.next(DefaultOfBizListIterator.java:100) at com.atlassian.jira.ofbiz.WrappingOfBizListIterator.next(WrappingOfBizListIterator.java:68) at com.atlassian.jira.crowd.embedded.ofbiz.OfBizUserDao.processUsers(OfBizUserDao.java:960) at com.atlassian.jira.crowd.embedded.ofbiz.DelegatingUserDao.processUsers(DelegatingUserDao.java:53) at com.atlassian.jira.crowd.embedded.ofbiz.IndexedUserDao.processUsers(IndexedUserDao.java:63) at com.atlassian.jira.crowd.embedded.ofbiz.DelegatingUserDao.processUsers(DelegatingUserDao.java:53) at com.atlassian.jira.crowd.embedded.ofbiz.SwitchingUserDao.processUsers(SwitchingUserDao.java:30) at com.atlassian.jira.application.DefaultApplicationRoleManager.lambda$readUsersInGroupsExcluding$23(DefaultApplicationRoleManager.java:1077) at com.atlassian.jira.application.DefaultApplicationRoleManager$$Lambda$800/1668537103.accept(Unknown Source) at com.atlassian.jira.crowd.embedded.ofbiz.db.DefaultOfBizTransaction.lambda$withTransaction$0(DefaultOfBizTransaction.java:44) at com.atlassian.jira.crowd.embedded.ofbiz.db.DefaultOfBizTransaction$$Lambda$801/1417043076.apply(Unknown Source) at com.atlassian.jira.crowd.embedded.ofbiz.db.DefaultOfBizTransaction.withTransaction(DefaultOfBizTransaction.java:28) at com.atlassian.jira.crowd.embedded.ofbiz.db.DefaultOfBizTransaction.withTransaction(DefaultOfBizTransaction.java:42) at com.atlassian.jira.crowd.embedded.ofbiz.db.DefaultOfBizTransactionManager.withTransaction(DefaultOfBizTransactionManager.java:9) at com.atlassian.jira.application.DefaultApplicationRoleManager.readUsersInGroupsExcluding(DefaultApplicationRoleManager.java:1076) at com.atlassian.jira.application.DefaultApplicationRoleManager.readUsersInGroups(DefaultApplicationRoleManager.java:1048) at com.atlassian.jira.application.DefaultApplicationRoleManager.countUsersInGroups(DefaultApplicationRoleManager.java:1100) at com.atlassian.jira.application.DefaultApplicationRoleManager.countApplicationRoleUsers(DefaultApplicationRoleManager.java:955) at com.atlassian.jira.application.DefaultApplicationRoleManager.countApplicationUsers(DefaultApplicationRoleManager.java:938) at com.atlassian.jira.application.DefaultApplicationRoleManager$$Lambda$796/449395834.apply(Unknown Source) at com.atlassian.fugue.Option.map(Option.java:272) at com.atlassian.jira.application.DefaultApplicationRoleManager.lambda$new$1(DefaultApplicationRoleManager.java:197) at com.atlassian.jira.application.DefaultApplicationRoleManager$$Lambda$189/365645537.load(Unknown Source) at com.atlassian.cache.ehcache.LoadingCache.getFromLoader(LoadingCache.java:145) at com.atlassian.cache.ehcache.LoadingCache.loadValueAndReleaseLock(LoadingCache.java:100) at com.atlassian.cache.ehcache.LoadingCache.get(LoadingCache.java:76) at com.atlassian.cache.ehcache.DelegatingCache.get(DelegatingCache.java:99) at com.atlassian.jira.cache.DeferredReplicationCache.get(DeferredReplicationCache.java:48) at com.atlassian.jira.application.DefaultApplicationRoleManager.lambda$getUserCountCurrentValue$16(DefaultApplicationRoleManager.java:583) at com.atlassian.jira.application.DefaultApplicationRoleManager$$Lambda$795/1812474572.apply(Unknown Source) at com.atlassian.fugue.Option$Some.fold(Option.java:421) at com.atlassian.jira.application.DefaultApplicationRoleManager.getUserCountCurrentValue(DefaultApplicationRoleManager.java:581) at com.atlassian.jira.application.DefaultApplicationRoleManager.getUserCount(DefaultApplicationRoleManager.java:574) at com.atlassian.jira.instrumentation.external.InternalStatisticsExternalGauges$1.lambda$new$1(InternalStatisticsExternalGauges.java:96) at com.atlassian.jira.instrumentation.external.InternalStatisticsExternalGauges$1$$Lambda$769/1512596918.get(Unknown Source) at com.atlassian.jira.monitoring.jmx.InstrumentationMetricsCollector.lambda$null$1(InstrumentationMetricsCollector.java:87) at com.atlassian.jira.monitoring.jmx.InstrumentationMetricsCollector$$Lambda$784/1964062498.get(Unknown Source) at com.atlassian.jira.monitoring.jmx.bean.DynamicJmxValue.lambda$getMBeanInfo$0(DynamicJmxValue.java:60) at com.atlassian.jira.monitoring.jmx.bean.DynamicJmxValue$$Lambda$785/55309983.apply(Unknown Source) ... at com.atlassian.jira.monitoring.jmx.bean.DynamicJmxValue.getMBeanInfo(DynamicJmxValue.java:66) at com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.getNewMBeanClassName(DefaultMBeanServerInterceptor.java:333) at com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.registerMBean(DefaultMBeanServerInterceptor.java:319) at com.sun.jmx.mbeanserver.JmxMBeanServer.registerMBean(JmxMBeanServer.java:522) at com.atlassian.jira.monitoring.jmx.JmxMetricsExposerImpl.register(JmxMetricsExposerImpl.java:56) at com.atlassian.jira.monitoring.jmx.JmxMetricsExposerImpl.startExposing(JmxMetricsExposerImpl.java:83) - locked <0x00000001cb97e198> (a java.lang.Object) at com.atlassian.jira.monitoring.jmx.JmxMetricsExposerImpl.refreshState(JmxMetricsExposerImpl.java:123) at com.atlassian.jira.monitoring.jmx.JmxMetricsExposerImpl.init(JmxMetricsExposerImpl.java:113) at com.atlassian.jira.instrumentation.Instrumentation.start(Instrumentation.java:168) at com.atlassian.jira.ComponentManager.runStartable(ComponentManager.java:312) at com.atlassian.jira.ComponentManager.quickStart(ComponentManager.java:225) at com.atlassian.jira.ComponentManager.start(ComponentManager.java:165) - locked <0x00000001c039d2d8> (a com.atlassian.jira.ComponentManager) at com.atlassian.jira.upgrade.PluginSystemLauncher.start(PluginSystemLauncher.java:47) at com.atlassian.jira.startup.DefaultJiraLauncher.lambda$postDbLaunch$2(DefaultJiraLauncher.java:154) at com.atlassian.jira.startup.DefaultJiraLauncher$$Lambda$80/1981519697.run(Unknown Source) at com.atlassian.jira.config.database.DatabaseConfigurationManagerImpl.doNowOrEnqueue(DatabaseConfigurationManagerImpl.java:304) at com.atlassian.jira.config.database.DatabaseConfigurationManagerImpl.doNowOrWhenDatabaseActivated(DatabaseConfigurationManagerImpl.java:199) at com.atlassian.jira.startup.DefaultJiraLauncher.postDbLaunch(DefaultJiraLauncher.java:146) at com.atlassian.jira.startup.DefaultJiraLauncher.lambda$start$0(DefaultJiraLauncher.java:105) at com.atlassian.jira.startup.DefaultJiraLauncher$$Lambda$28/2068762689.run(Unknown Source) at com.atlassian.jira.util.devspeed.JiraDevSpeedTimer.run(JiraDevSpeedTimer.java:31) at com.atlassian.jira.startup.DefaultJiraLauncher.start(DefaultJiraLauncher.java:103) at com.atlassian.jira.startup.LauncherContextListener.initSlowStuff(LauncherContextListener.java:157) at com.atlassian.jira.startup.LauncherContextListener.initSlowStuffInBackground(LauncherContextListener.java:142) at com.atlassian.jira.startup.LauncherContextListener.contextInitialized(LauncherContextListener.java:104) at org.apache.catalina.core.StandardContext.listenerStart(StandardContext.java:4727) at org.apache.catalina.core.StandardContext.startInternal(StandardContext.java:5189)
- Notice that during startup, the JMX monitoring is loaded, which then spends time getting users for license count.
at com.atlassian.jira.application.DefaultApplicationRoleManager.readUsersInGroups(DefaultApplicationRoleManager.java:1048) at com.atlassian.jira.application.DefaultApplicationRoleManager.countUsersInGroups(DefaultApplicationRoleManager.java:1100) at com.atlassian.jira.application.DefaultApplicationRoleManager.countApplicationRoleUsers(DefaultApplicationRoleManager.java:955) at com.atlassian.jira.application.DefaultApplicationRoleManager.countApplicationUsers(DefaultApplicationRoleManager.java:938)
Workaround
Disable JMX Monitoring before restarting Jira.
- causes
-
-
- Closed
-
- is related to
-
JRASERVER-67466 Expose Jira and performance metrics through JMX (part1)
- Closed
- relates to
-
-
- Closed
-
- mentioned in
-
Page Loading...