EAP 7 start up slowness in ServiceModuleLoader.preloadModule

Solution Verified - Updated

Environment

  • JBoss Enterprise Application Platform (EAP) 7.x

Issue

  • We see slowness during start up with a large ear in org.jboss.as.server.moduleservice.ServiceModuleLoader.preloadModule calls. This was not seen previously on EAP 6:
"MSC service thread 1-8" #26 prio=5 os_prio=0 tid=0x00005635d2431800 nid=0x357c waiting for monitor entry [0x00007f1dae332000]
   java.lang.Thread.State: BLOCKED (on object monitor)
	at org.jboss.as.server.moduleservice.ServiceModuleLoader.preloadModule(ServiceModuleLoader.java:142)
	- waiting to lock <0x00000006c026f2e0> (a java.lang.Class for org.jboss.as.server.moduleservice.ServiceModuleLoader)
	at org.jboss.modules.ModuleLoader.preloadModule(ModuleLoader.java:404)
	at org.jboss.modules.Module.addExportedPaths(Module.java:1425)
	at org.jboss.modules.Module.addExportedPaths(Module.java:1473)
	at org.jboss.modules.Module.addExportedPaths(Module.java:1473)
	at org.jboss.modules.Module.addExportedPaths(Module.java:1473)
	at org.jboss.modules.Module.addExportedPaths(Module.java:1473)
	at org.jboss.modules.Module.addExportedPaths(Module.java:1473)
	at org.jboss.modules.Module.addExportedPaths(Module.java:1473)
	at org.jboss.modules.Module.addExportedPaths(Module.java:1473)
	at org.jboss.modules.Module.addExportedPaths(Module.java:1473)
	at org.jboss.modules.Module.addExportedPaths(Module.java:1473)
	at org.jboss.modules.Module.addExportedPaths(Module.java:1473)
	at org.jboss.modules.Module.addExportedPaths(Module.java:1473)
	at org.jboss.modules.Module.addExportedPaths(Module.java:1473)
	at org.jboss.modules.Module.addPaths(Module.java:1317)
	at org.jboss.modules.Module.link(Module.java:1644)
	at org.jboss.modules.Module.relink(Module.java:1688)
	at org.jboss.modules.ModuleLoader.relink(ModuleLoader.java:827)
	at org.jboss.as.server.moduleservice.ServiceModuleLoader.relinkModule(ServiceModuleLoader.java:201)
	at org.jboss.as.server.moduleservice.ModuleLoadService.start(ModuleLoadService.java:94)
	- locked <0x00000006d4a00540> (a org.jboss.as.server.moduleservice.ModuleLoadService)
	at org.jboss.msc.service.ServiceControllerImpl$StartTask.startService(ServiceControllerImpl.java:1739)
	at org.jboss.msc.service.ServiceControllerImpl$StartTask.execute(ServiceControllerImpl.java:1701)
	at org.jboss.msc.service.ServiceControllerImpl$ControllerTask.run(ServiceControllerImpl.java:1559)
	at org.jboss.threads.ContextClassLoaderSavingRunnable.run(ContextClassLoaderSavingRunnable.java:35)
	at org.jboss.threads.EnhancedQueueExecutor.safeRun(EnhancedQueueExecutor.java:1990)
	at org.jboss.threads.EnhancedQueueExecutor$ThreadBody.doRunTask(EnhancedQueueExecutor.java:1486)
	at org.jboss.threads.EnhancedQueueExecutor$ThreadBody.run(EnhancedQueueExecutor.java:1363)
	at java.lang.Thread.run(Thread.java:750)

"MSC service thread 1-2" #20 prio=5 os_prio=0 tid=0x00005635d1edf800 nid=0x3576 waiting for monitor entry [0x00007f1dae93b000]
   java.lang.Thread.State: BLOCKED (on object monitor)
	at org.jboss.as.server.moduleservice.ServiceModuleLoader.preloadModule(ServiceModuleLoader.java:142)
	- locked <0x00000006c026f2e0> (a java.lang.Class for org.jboss.as.server.moduleservice.ServiceModuleLoader)
	at org.jboss.modules.ModuleLoader.preloadModule(ModuleLoader.java:404)
	at org.jboss.modules.Module.addExportedPaths(Module.java:1425)
	at org.jboss.modules.Module.addExportedPaths(Module.java:1473)
	at org.jboss.modules.Module.addPaths(Module.java:1317)
	at org.jboss.modules.Module.link(Module.java:1644)
	at org.jboss.modules.Module.relink(Module.java:1688)
	at org.jboss.modules.ModuleLoader.relink(ModuleLoader.java:827)
	at org.jboss.as.server.moduleservice.ServiceModuleLoader.relinkModule(ServiceModuleLoader.java:201)
	at org.jboss.as.server.moduleservice.ModuleLoadService.start(ModuleLoadService.java:94)
	- locked <0x00000006d1915830> (a org.jboss.as.server.moduleservice.ModuleLoadService)
	at org.jboss.msc.service.ServiceControllerImpl$StartTask.startService(ServiceControllerImpl.java:1739)
	at org.jboss.msc.service.ServiceControllerImpl$StartTask.execute(ServiceControllerImpl.java:1701)
	at org.jboss.msc.service.ServiceControllerImpl$ControllerTask.run(ServiceControllerImpl.java:1559)
	at org.jboss.threads.ContextClassLoaderSavingRunnable.run(ContextClassLoaderSavingRunnable.java:35)
	at org.jboss.threads.EnhancedQueueExecutor.safeRun(EnhancedQueueExecutor.java:1990)
	at org.jboss.threads.EnhancedQueueExecutor$ThreadBody.doRunTask(EnhancedQueueExecutor.java:1486)
	at org.jboss.threads.EnhancedQueueExecutor$ThreadBody.run(EnhancedQueueExecutor.java:1363)
	at java.lang.Thread.run(Thread.java:750)

Resolution

  • Ensure the ear's META-INF/application.xml has not changed its <library-directory>
<library-directory>lib</library-directory>

## Root Cause

* The [WFCORE-2235](https://issues.redhat.com/browse/WFCORE-2235) fix new to EAP 7 added too much synchronization.  This adds a bottleneck to modules being loaded and linked together.  An ear is not isolated by default so a large ear can result in a lot of operations cross referencing dependencies across its included jars/wars that gets slowed down on the `org.jboss.as.server.moduleservice.ServiceModuleLoader.preloadModule` lock.
* [WFCORE-6188](https://issues.redhat.com/browse/WFCORE-6188)
* [JBEAP-24410](https://issues.redhat.com/browse/JBEAP-24410)
* If an ear has changed its `<library-directory>`, it would not appropriately load jars inherently from the lib directory.  jars would then only become loaded as a result of the ear MANIFEST.MF Class-Path entries and then the Class-Path entries of those loaded jars and so on and each jar would become its own individual module that the ear depends on.  Multiple Class-Path entries across these jars pointing to the same jars results in them being added multiple times each as a dependency to the ear.  And so this may result in hundreds or thousands of dependencies on the ear that is then inherited by all its loaded jars/ears.  This module dependency processing then becomes heavily slowed by the above synchronization as well.
    * [WFCORE-6199](https://issues.redhat.com/browse/WFCORE-6199)
* In EAP 7.1.0+, ModuleIdentifier's were deprecated by [MODULES-256](https://issues.redhat.com/browse/MODULES-256), which can decrease performance for repeating Module operations
    * [MODULES-435](https://issues.redhat.com/browse/MODULES-435)
    * [WFCORE-6211](https://issues.redhat.com/browse/WFCORE-6211)

## Diagnostic Steps

* Capture a heap dump after start.  Run the following OQL and check the number of modules and their dependency counts:

SELECT module.name.toString(), allDependencies.size, localDependencies.list.size FROM org.jboss.as.server.moduleservice.ModuleLoadService

* Any modules entries like `deployment.app.ear.lib/*.jar` would indicate that the ear does not have an appropriately set lib directory
* Check the application `META-INF/application.xml` for a modified `<library-directory>` setting
Components
Category

This solution is part of Red Hat’s fast-track publication program, providing a huge library of solutions that Red Hat engineers have created while supporting our customers. To give you the knowledge you need the instant it becomes available, these articles may be presented in a raw and unedited form.