search

krasa / VisualVMLauncher

IntelliJ plugin - https://plugins.jetbrains.com/plugin/7115
Apache License 2.0
107 stars 19 forks source link

VisualVM not profiling #29

Open 4ntoine opened 5 years ago

4ntoine commented 5 years ago

I'm trying to run the test on Intellij idea 2019.1.3 CE on mac. I can see VisualVM is starting but showing error "cannot open requested application":

Снимок экрана 2019-07-23 в 12 23 11 
$java -version
java version "1.8.0_121"
Java(TM) SE Runtime Environment (build 1.8.0_121-b13)
Java HotSpot(TM) 64-Bit Server VM (build 25.121-b13, mixed mode)

Any thoughts?

4ntoine commented 5 years ago

Tried default jvm visualvm:

Снимок экрана 2019-07-23 в 13 48 05

and 1.4.3 installed manually:

Снимок экрана 2019-07-23 в 13 49 20
krasa commented 5 years ago

Maybe -Dvisualvm.id=... does not match.

Does this button work? https://user-images.githubusercontent.com/1160875/61697788-4c37a600-ad38-11e9-860f-7c2ade17ea39.png

Does VisualVM even show that process?

4ntoine commented 5 years ago

FYI just tried for IDEA 2018.2.8 - getting the same error. The button works and VisualVM is started but getting the same error right after it.

4ntoine commented 5 years ago

Can you explain more about -Dvisualvm.id=... ?

4ntoine commented 5 years ago

Does VisualVM even show that process?

Yup:

Снимок экрана 2019-07-23 в 16 31 24
krasa commented 5 years ago

If you enable debug log ( Menu | Help | Debug Log...) for krasa.visualvm you should see something like this:

2019-07-23 14:51:08,542 [10545065]  DEBUG -       krasa.visualvm.LogHelper - DebugVisualVMRunner: #createContentDescriptor
2019-07-23 14:51:08,545 [10545068]  DEBUG -       krasa.visualvm.LogHelper - DebugVisualVMRunner: #createContentDescriptor -Dvisualvm.id=681312417627178
2019-07-23 14:51:08,545 [10545068]  DEBUG -       krasa.visualvm.LogHelper - VisualVMJavaProgramPatcher: #patchJavaParameters start
2019-07-23 14:51:08,545 [10545068]  DEBUG -       krasa.visualvm.LogHelper - VisualVMJavaProgramPatcher: Patching: jdkPath=null; appId=681315535965486
2019-07-23 14:51:08,545 [10545068]  DEBUG - krasa.visualvm.VisualVMContext - saving context: VisualVMContext{appId=681315535965486}
2019-07-23 14:51:08,557 [10545080]  DEBUG -       krasa.visualvm.LogHelper - StartVisualVMConsoleAction: created with VisualVMContext{appId=681315535965486}
2019-07-23 14:51:08,581 [10545104]  DEBUG -       krasa.visualvm.LogHelper - DebugVisualVMRunner: #attachVirtualMachine
2019-07-23 14:51:08,581 [10545104]  DEBUG -       krasa.visualvm.LogHelper - DebugVisualVMRunner: starting VisualVM with id=681312417627178
2019-07-23 14:51:19,283 [10555806]  DEBUG -       krasa.visualvm.LogHelper - StartVisualVMConsoleAction: created with VisualVMContext{appId=681315535965486}

That's how VisualVM knows which app to open. Sometimes there are 2 ids and only one of them is being used, that's fine. But it is possible that some other id from some other process is being used for starting VisualVM.

4ntoine commented 5 years ago
Снимок экрана 2019-07-23 в 18 14 19

Nothing in the log:

Снимок экрана 2019-07-23 в 18 16 55

But i can see ids in cmd:

/Library/Java/JavaVirtualMachines/jdk1.8.0_121.jdk/Contents/Home/bin/java -agentlib:jdwp=transport=dt_socket,address=127.0.0.1:55012,suspend=y,server=n -Dvisualvm.id=883655423944663 -ea -Didea.test.cyclic.buffer.size=1048576 -Dvisualvm.id=883642351419808 ...

krasa commented 5 years ago

IntelliJ log. 'Help| Show Log in explorer or something.'

4ntoine commented 5 years ago

yup, i can see it:

2019-07-23 18:06:22,657 [23681771]  DEBUG -       krasa.visualvm.LogHelper - StartVisualVMConsoleAction: created with VisualVMContext{appId=882071234567842} 
2019-07-23 18:06:22,661 [23681775]  DEBUG -       krasa.visualvm.LogHelper - StartVisualVMConsoleAction: created with VisualVMContext{appId=882071234567842} 
2019-07-23 18:06:27,736 [23686850]   INFO - mponents.impl.stores.StoreUtil - saveProjectsAndApp took 60 ms 
2019-07-23 18:06:29,508 [23688622]   INFO - ild.invoker.GradleBuildInvoker - Gradle build finished in 6 s 898 ms 
2019-07-23 18:06:29,536 [23688650]   INFO - pl.ProjectRootManagerComponent - project roots have changed 
2019-07-23 18:06:29,554 [23688668]  DEBUG -       krasa.visualvm.LogHelper - VisualVMJavaProgramPatcher: #patchJavaParameters start 
2019-07-23 18:06:29,555 [23688669]  DEBUG -       krasa.visualvm.LogHelper - VisualVMJavaProgramPatcher: Patching: jdkPath=null; appId=882975128538931 
2019-07-23 18:06:29,555 [23688669]  DEBUG - krasa.visualvm.VisualVMContext - saving context: VisualVMContext{appId=882975128538931} 
2019-07-23 18:06:29,557 [23688671]  DEBUG -       krasa.visualvm.LogHelper - StartVisualVMConsoleAction: created with VisualVMContext{appId=882975128538931} 
2019-07-23 18:06:29,663 [23688777]   INFO - pl.ProjectRootManagerComponent - project roots have changed 
2019-07-23 18:06:29,696 [23688810]   INFO - pl.ProjectRootManagerComponent - project roots have changed 
2019-07-23 18:06:29,788 [23688902]   INFO - .diagnostic.PerformanceWatcher - Pushing properties took 1ms; general responsiveness: ok; EDT responsiveness: ok 
2019-07-23 18:06:29,825 [23688939]   INFO - .diagnostic.PerformanceWatcher - Indexable file iteration took 37ms; general responsiveness: ok; EDT responsiveness: ok 
2019-07-23 18:06:36,025 [23695139]  DEBUG - krasa.visualvm.VisualVMContext - saving context: VisualVMContext{appId=882981599267630} 
2019-07-23 18:06:36,027 [23695141]  DEBUG -       krasa.visualvm.LogHelper - RunVisualVMRunner: #execute 
2019-07-23 18:06:36,069 [23695183]   INFO - ild.invoker.GradleBuildInvoker - About to execute Gradle tasks: [:compat:generateDebugSources, :compat:generateDebugAndroidTestSources, :compat:createMockableJar, :compat:compileDebugAndroidTestSources, :compat:compileDebugUnitTestSources, :compat:compileDebugSources] 
2019-07-23 18:06:36,074 [23695188]   INFO - s.plugins.gradle.GradleManager - Instructing gradle to use java from /Library/Java/JavaVirtualMachines/jdk1.8.0_121.jdk/Contents/Home 
2019-07-23 18:06:36,075 [23695189]   INFO - ild.invoker.GradleBuildInvoker - Build command line options: [-Pandroid.injected.invoked.from.ide=true] 
2019-07-23 18:06:36,078 [23695192]   INFO - xecution.GradleExecutionHelper - Passing command-line args to Gradle Tooling API: -Pandroid.injected.invoked.from.ide=true 
2019-07-23 18:06:36,120 [23695234]  DEBUG -       krasa.visualvm.LogHelper - StartVisualVMConsoleAction: created with VisualVMContext{appId=882981599267630} 
2019-07-23 18:06:36,123 [23695237]  DEBUG -       krasa.visualvm.LogHelper - StartVisualVMConsoleAction: created with VisualVMContext{appId=882981599267630}
4ntoine commented 5 years ago

anything i can check to help you fix it?

krasa commented 5 years ago

Do you have an example project? I've tried gradle+kotlin and it worked fine, except when it would not support VisualVM and YourKit at all, since it runned tests via gradle goals only.

4ntoine commented 5 years ago

Basically any project tests can be launched with visualvm. i've just checked https://github.com/4ntoine/NotesServerApp/blob/master/infra-gateway-ormlite/src/test/kotlin/name/antonsmirnov/notes/gateway/OrmLiteGatewayTest.kt