How to CPU Profile Wildfly10 using VisualVM?

Question

Problem: I have an J2EE application that is running very slow for a given task (to generate some files) using a specific data set. I decided to run the visualvm profiler over the application to understand the nature of the problem. The application is running over Widlfly 10 using the latest Java 8.

To avoid configuration complexity, both profiler (visualvm) and Wildfly server are running locally.

The first problem met was the JVMTI error 62, that was resolved using the -Xverify:none as jvm parameter.

The second problem (the blocking one) is that if I run the profiler when the application is deployed and running, the Wildfly deployment scanner throws Exceptions like this one:

13:19:04,476 INFO  [stdout] (*** Profiler Agent Communication Thread) Profiler Agent: Waiting for connection on port 5140 (Protocol version: 15)

13:19:04,517 INFO  [stdout] (*** Profiler Agent Communication Thread) Profiler Agent: Established connection with the tool

13:19:04,847 INFO  [stdout] (*** Profiler Agent Communication Thread) Profiler Agent: Local accelerated session

13:19:15,984 WARN  [org.jboss.as.ejb3.timer] (EJB default - 6) WFLYEJB0043: A previous execution of timer [id=e6a6ea46-6c2a-466d-b767-cccc8d5021a9 timedObjectId=ecs.ecs.BatchCoordinator auto-timer?:false persistent?:false timerService=org.jboss.as.ejb3.timerservice.TimerServiceImpl@142b16ca initialExpiration=Sun Aug 05 13:17:05 COT 2018 intervalDuration(in milli sec)=5000 nextExpiration=Sun Aug 05 13:19:15 COT 2018 timerState=IN_TIMEOUT info=null] is still in progress, skipping this overlapping scheduled execution at: Sun Aug 05 13:19:15 COT 2018.
13:19:16,025 ERROR [org.jboss.as.controller.management-operation] (DeploymentScanner-threads - 1) WFLYCTL0013: Operation ("read-resource") failed - address: ([("deployment" => "my_application.war")]): java.lang.NoClassDefFoundError: org/jboss/as/controller/AttributeDefinition$$Lambda$157
at org.jboss.as.controller.AttributeDefinition$$Lambda$157/1799183343.get$Lambda(Unknown Source)
at org.jboss.as.controller.AttributeDefinition.getNoTextDescription(AttributeDefinition.java:872)
at org.jboss.as.controller.AttributeDefinition.addResourceAttributeDescription(AttributeDefinition.java:697)
at org.jboss.as.controller.ListAttributeDefinition.addResourceAttributeDescription(ListAttributeDefinition.java:158)
at org.jboss.as.controller.descriptions.DefaultResourceDescriptionProvider.getModelDescription(DefaultResourceDescriptionProvider.java:129)
at org.jboss.as.controller.operations.global.ReadResourceHandler.doExecuteInternal(ReadResourceHandler.java:370)
at org.jboss.as.controller.operations.global.ReadResourceHandler.doExecute(ReadResourceHandler.java:173)
at org.jboss.as.controller.operations.global.GlobalOperationHandlers$AbstractMultiTargetHandler.execute(GlobalOperationHandlers.java:263)
at org.jboss.as.controller.AbstractOperationContext.executeStep(AbstractOperationContext.java:890)
at org.jboss.as.controller.AbstractOperationContext.processStages(AbstractOperationContext.java:659)
at org.jboss.as.controller.AbstractOperationContext.executeOperation(AbstractOperationContext.java:370)
at org.jboss.as.controller.OperationContextImpl.executeOperation(OperationContextImpl.java:1329)
at org.jboss.as.controller.ModelControllerImpl.internalExecute(ModelControllerImpl.java:400)
at org.jboss.as.controller.ModelControllerImpl.execute(ModelControllerImpl.java:208)
at org.jboss.as.controller.ModelControllerImpl$3.execute(ModelControllerImpl.java:667)
at org.jboss.as.controller.ModelControllerImpl$3.execute(ModelControllerImpl.java:657)
at org.jboss.as.server.deployment.scanner.DefaultDeploymentOperations.getDeploymentsStatus(DefaultDeploymentOperations.java:76)
at org.jboss.as.server.deployment.scanner.FileSystemDeploymentService$ScanContext.<init>(FileSystemDeploymentService.java:1622)
at org.jboss.as.server.deployment.scanner.FileSystemDeploymentService$ScanContext.<init>(FileSystemDeploymentService.java:1571)
at org.jboss.as.server.deployment.scanner.FileSystemDeploymentService.scan(FileSystemDeploymentService.java:572)
at org.jboss.as.server.deployment.scanner.FileSystemDeploymentService.scan(FileSystemDeploymentService.java:491)
at org.jboss.as.server.deployment.scanner.FileSystemDeploymentService$DeploymentScanRunnable.run(FileSystemDeploymentService.java:250)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
at java.lang.Thread.run(Thread.java:748)
at org.jboss.threads.JBossThread.run(JBossThread.java:320)

Caused by: java.lang.ClassNotFoundException: org.jboss.as.controller.AttributeDefinition$$Lambda$157 from [Module "org.jboss.as.controller:main" from local module loader @4cc77c2e (finder: local module finder @7a7b0070 (roots: D:\jbossas\wildfly-10.1.0.Final-ecs\modules,D:\jbossas\wildfly-10.1.0.Final-ecs\modules\system\layers\base))]
at org.jboss.modules.ModuleClassLoader.findClass(ModuleClassLoader.java:198)
at org.jboss.modules.ConcurrentClassLoader.performLoadClassUnchecked(ConcurrentClassLoader.java:363)
at org.jboss.modules.ConcurrentClassLoader.performLoadClass(ConcurrentClassLoader.java:351)
at org.jboss.modules.ConcurrentClassLoader.loadClass(ConcurrentClassLoader.java:93)
... 30 more

If I run the profiler without any deployed application, VisualVM's profiler starts without problems; however, if I tried to deploy my application under this state/operation mode, the wildfly scanner never starts and the application is never deployed.

So, What I'm doing wrong??

Answer 1

Finally, I put to work the visualVM Profiler... These are the steps that you need to do in order to execute a Wildfly 10 CPU profile using VisualVM (both executed locally!!):

1. Download the latest VisualVM (In my case was the version 1.4.1).

2. Download JDK10 ... You will need the JDK10 in order to run the VisualVM only. This step is required because of this bug (this was the bug that I was getting before when profiling the application)

3. Change the visualVM configuration file (<visual-vm>/etc/visualvm.conf) to point to your JDK10 installation...

4. Go to <visual-vm>/profiler/lib and copy the library: jfluid-server.jar into: <wildfly>/standalone/lib/ext ... This library is required to overcome the following error: java.lang.NoClassDefFoundError: org/netbeans/lib/profiler/server/ProfilerRuntimeCPUFullInstr (More about this error in here and here)

5. Next, modify the wildfly startup script to include the package org.netbeans.lib.profiler.server in the SystemProperty: jboss.modules.system.pkgs. Example: -Djboss.modules.system.pkgs=org.jboss.byteman,org.netbeans.lib.profiler.server. (According to this link, this property forces the wildfly to locate such package from any classloader)

6. Start the visualVM.

7. Start the wildfly server (including your application EAR/WAR/JAR application)... NOTE: I was running the wildfly server from Eclipse using JBoss Tools; under this configuration, my application (WAR) was in exploded mode!

8. Go to visualVM, open the org.jboss.modules.Main process. Then go to the profiler tab. Modify the target Profile classes and Outgoing calls and put the Classes that you want to monitor/profile (NOTE: For now, the winner configuration for me was: Profile classes: my.package.** and Include outgoing calls: my.package.**)

9. Hit the CPU Button, wait for the VisualVM to instrument your target classes and then invoke the code that is running slow; later, analyze the results...