pantsbuild / intellij-pants-plugin

IntelliJ Plug-in for Pants Build
Apache License 2.0
73 stars 55 forks source link

IntelliJ locking up when importing a new project #51

Closed ericzundel closed 9 years ago

ericzundel commented 9 years ago

I'm seeing IntelliJ 14.1.3 with the Plugin version 1.3.4 on my MacBook pro running MacOS 10.0 lock up and take 100% cpu when using the Plugin for IntelliJ. This is right after importing a new project using Pants to import a directory. I've seen this a few times now, so I sat down to do some diagnosis.

At this point I don't think its 100% locked up, but running very slowly.

screen shot 2015-08-29 at 11 35 03 am

The reason I say its running slowly is that it did finally finish the opening dialogs and now shows the project tree

Top shows the idea process eating CPU

screen shot 2015-08-29 at 11 34 50 am screen shot 2015-08-29 at 11 45 25 am

When running 'jstack' I see this stacktrace running (I took 4 dumps over a period of about 10 minutes and it was always there)

"ApplicationImpl pooled thread 10" #57 prio=4 os_prio=31 tid=0x0000000102e69000 nid=0x7a13 runnable [0x0000000135a9a000]
   java.lang.Thread.State: RUNNABLE
        at java.util.HashMap.resize(HashMap.java:734)
        at java.util.HashMap.putVal(HashMap.java:662)
        at java.util.HashMap.put(HashMap.java:611)
        at java.util.HashSet.add(HashSet.java:219)
        at java.util.AbstractCollection.addAll(AbstractCollection.java:344)
        at com.intellij.openapi.roots.impl.RootIndex.a(RootIndex.java:233)
        at com.intellij.openapi.roots.impl.RootIndex.a(RootIndex.java:214)
        at com.intellij.openapi.roots.impl.RootIndex.getOrderEntries(RootIndex.java:618)
        at com.intellij.openapi.roots.impl.DirectoryIndexImpl.getOrderEntries(DirectoryIndexImpl.java:192)
        at com.intellij.openapi.roots.impl.ProjectFileIndexImpl.getOrderEntriesForFile(ProjectFileIndexImpl.java:112)
        at com.jetbrains.python.psi.impl.PythonLanguageLevelPusher.findSdk(PythonLanguageLevelPusher.java:129)
        at com.jetbrains.python.psi.impl.PythonLanguageLevelPusher.getFileSdk(PythonLanguageLevelPusher.java:123)
        at com.jetbrains.python.psi.impl.PythonLanguageLevelPusher.getFileLanguageLevel(PythonLanguageLevelPusher.java:110)
        at com.jetbrains.python.psi.impl.PythonLanguageLevelPusher.getImmediateValue(PythonLanguageLevelPusher.java:102)
        at com.jetbrains.python.psi.impl.PythonLanguageLevelPusher.getImmediateValue(PythonLanguageLevelPusher.java:65)
        at com.intellij.openapi.roots.impl.PushedFilePropertiesUpdaterImpl.a(PushedFilePropertiesUpdaterImpl.java:218)
        at com.intellij.openapi.roots.impl.PushedFilePropertiesUpdaterImpl.findAndUpdateValue(PushedFilePropertiesUpdaterImpl.java:318)
        at com.intellij.openapi.roots.impl.PushedFilePropertiesUpdaterImpl.b(PushedFilePropertiesUpdaterImpl.java:307)
        at com.intellij.openapi.roots.impl.PushedFilePropertiesUpdaterImpl.access$1000(PushedFilePropertiesUpdaterImpl.java:63)
        at com.intellij.openapi.roots.impl.PushedFilePropertiesUpdaterImpl$11.run(PushedFilePropertiesUpdaterImpl.java:293)
        at com.intellij.openapi.application.impl.ApplicationImpl.runReadAction(ApplicationImpl.java:872)
        at com.intellij.openapi.roots.impl.PushedFilePropertiesUpdaterImpl.a(PushedFilePropertiesUpdaterImpl.java:288)
        at com.intellij.openapi.roots.impl.PushedFilePropertiesUpdaterImpl.access$700(PushedFilePropertiesUpdaterImpl.java:63)
        at com.intellij.openapi.roots.impl.PushedFilePropertiesUpdaterImpl$10$1$1.processFile(PushedFilePropertiesUpdaterImpl.java:275)
        at com.intellij.openapi.vfs.VfsUtilCore$1.visitFileEx(VfsUtilCore.java:252)
        at com.intellij.openapi.vfs.VfsUtilCore.visitChildrenRecursively(VfsUtilCore.java:267)
        at com.intellij.openapi.vfs.VfsUtilCore.visitChildrenRecursively(VfsUtilCore.java:299)
        at com.intellij.openapi.vfs.VfsUtilCore.visitChildrenRecursively(VfsUtilCore.java:299)
        at com.intellij.openapi.vfs.VfsUtilCore.visitChildrenRecursively(VfsUtilCore.java:299)
        at com.intellij.openapi.vfs.VfsUtilCore.visitChildrenRecursively(VfsUtilCore.java:299)
        at com.intellij.openapi.vfs.VfsUtilCore.visitChildrenRecursively(VfsUtilCore.java:299)
        at com.intellij.openapi.vfs.VfsUtilCore.visitChildrenRecursively(VfsUtilCore.java:299)
        at com.intellij.openapi.vfs.VfsUtilCore.visitChildrenRecursively(VfsUtilCore.java:299)
        at com.intellij.openapi.vfs.VfsUtilCore.iterateChildrenRecursively(VfsUtilCore.java:247)
        at com.intellij.openapi.roots.impl.ModuleFileIndexImpl.iterateContent(ModuleFileIndexImpl.java:56)
        at com.intellij.openapi.roots.impl.PushedFilePropertiesUpdaterImpl$10$1.run(PushedFilePropertiesUpdaterImpl.java:272)
        at com.intellij.openapi.roots.impl.PushedFilePropertiesUpdaterImpl.a(PushedFilePropertiesUpdaterImpl.java:283)
        at com.intellij.openapi.roots.impl.PushedFilePropertiesUpdaterImpl.pushAllPropertiesNow(PushedFilePropertiesUpdaterImpl.java:153)
        at com.intellij.util.indexing.UnindexedFilesUpdater.a(UnindexedFilesUpdater.java:64)
        at com.intellij.util.indexing.UnindexedFilesUpdater.performInDumbMode(UnindexedFilesUpdater.java:114)
        at com.intellij.openapi.project.DumbServiceImpl$8.run(DumbServiceImpl.java:416)
        at com.intellij.openapi.progress.impl.CoreProgressManager$2.run(CoreProgressManager.java:152)
        at com.intellij.openapi.progress.impl.CoreProgressManager.a(CoreProgressManager.java:452)
        at com.intellij.openapi.progress.impl.CoreProgressManager.executeProcessUnderProgress(CoreProgressManager.java:402)
  at com.intellij.openapi.progress.impl.ProgressManagerImpl.executeProcessUnderProgress(ProgressManagerImpl.java:54)
        at com.intellij.openapi.progress.impl.CoreProgressManager.runProcess(CoreProgressManager.java:137)
        at com.intellij.openapi.project.DumbServiceImpl.a(DumbServiceImpl.java:407)
        at com.intellij.openapi.project.DumbServiceImpl.access$1100(DumbServiceImpl.java:52)
        at com.intellij.openapi.project.DumbServiceImpl$7.run(DumbServiceImpl.java:389)
        at com.intellij.openapi.progress.impl.CoreProgressManager$TaskRunnable.run(CoreProgressManager.java:563)
        at com.intellij.openapi.progress.impl.CoreProgressManager$2.run(CoreProgressManager.java:152)
        at com.intellij.openapi.progress.impl.CoreProgressManager.a(CoreProgressManager.java:452)
        at com.intellij.openapi.progress.impl.CoreProgressManager.executeProcessUnderProgress(CoreProgressManager.java:402)
        at com.intellij.openapi.progress.impl.ProgressManagerImpl.executeProcessUnderProgress(ProgressManagerImpl.java:54)
        at com.intellij.openapi.progress.impl.CoreProgressManager.runProcess(CoreProgressManager.java:137)
        at com.intellij.openapi.progress.impl.ProgressManagerImpl$1.run(ProgressManagerImpl.java:126)
        at com.intellij.openapi.application.impl.ApplicationImpl$8.run(ApplicationImpl.java:400)
        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
        at java.util.concurrent.FutureTask.run(FutureTask.java:266)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
        at java.lang.Thread.run(Thread.java:745)
        at org.jetbrains.ide.PooledThreadExecutor$1$1.run(PooledThreadExecutor.java:56)

The heap seems OK to me (lots of free space)

cat /tmp/heap-26389.out 
Attaching to process ID 26389, please wait...
Debugger attached successfully.
Server compiler detected.
JVM version is 25.45-b02

using parallel threads in the new generation.
using thread-local object allocation.
Concurrent Mark-Sweep GC

Heap Configuration:
   MinHeapFreeRatio         = 40
   MaxHeapFreeRatio         = 70
   MaxHeapSize              = 4294967296 (4096.0MB)
   NewSize                  = 697892864 (665.5625MB)
   MaxNewSize               = 697892864 (665.5625MB)
   OldSize                  = 1449590784 (1382.4375MB)
   NewRatio                 = 2
   SurvivorRatio            = 8
   MetaspaceSize            = 21807104 (20.796875MB)
   CompressedClassSpaceSize = 1073741824 (1024.0MB)
   MaxMetaspaceSize         = 17592186044415 MB
   G1HeapRegionSize         = 0 (0.0MB)

Heap Usage:
New Generation (Eden + 1 Survivor Space):
   capacity = 628162560 (599.0625MB)
   used     = 87528152 (83.47335052490234MB)
   free     = 540634408 (515.5891494750977MB)
   13.933996957730177% used
Eden Space:
   capacity = 558432256 (532.5625MB)
   used     = 53194504 (50.73023223876953MB)
   free     = 505237752 (481.83226776123047MB)
   9.525686138015638% used
From Space:
   capacity = 69730304 (66.5MB)
   used     = 34333648 (32.74311828613281MB)
   free     = 35396656 (33.75688171386719MB)
   49.23777185884634% used
To Space:
   capacity = 69730304 (66.5MB)
   used     = 0 (0.0MB)
   free     = 69730304 (66.5MB)
   0.0% used
concurrent mark-sweep generation:
   capacity = 1449590784 (1382.4375MB)
   used     = 7714773562038266448 (7.3573814030058545E12MB)
   free     = 10234804642792 MB
   5.32203546489867E11% used

74479 interned Strings occupying 8069856 bytes.

I eventually killed the idea process and restarted intelliJ. It came back up and now I can see the project.

ericzundel commented 9 years ago

OK, I take it back. When I expanded the project I can only see the files in the root directory of the repo I can't use this project. There should be a lot more files there.

screen shot 2015-08-29 at 12 04 03 pm
ericzundel commented 9 years ago

I believe this is the log file for the run that was hanging but I'm not sure.

https://gist.github.com/ericzundel/a3174dd3e7d0fdafbc82

I am upgrading IntelliJ and all my plugins to see if that helps

ericzundel commented 9 years ago

I updated to IntelliJ 14.1.4 and upgraded all of my plugins.

I performed the same import of the same project. The IntelliJ window is beachballed 12 minutes into the process (this is a pretty small project)

Here's the top of that same thread from jstack:

"ApplicationImpl pooled thread 8" #52 prio=4 os_prio=31 tid=0x000000013501c800 nid=0x13347 runnable [0x00000001344fe000]
   java.lang.Thread.State: RUNNABLE
        at java.util.HashMap.hash(HashMap.java:338)
        at java.util.HashMap.put(HashMap.java:611)
        at java.util.HashSet.add(HashSet.java:219)
        at java.util.AbstractCollection.addAll(AbstractCollection.java:344)
        at com.intellij.openapi.roots.impl.RootIndex.a(RootIndex.java:233)
        at com.intellij.openapi.roots.impl.RootIndex.a(RootIndex.java:214)
        at com.intellij.openapi.roots.impl.RootIndex.getOrderEntries(RootIndex.java:618)
        at com.intellij.openapi.roots.impl.DirectoryIndexImpl.getOrderEntries(DirectoryIndexImpl.java:192)
        at com.intellij.openapi.roots.impl.ProjectFileIndexImpl.getOrderEntriesForFile(ProjectFileIndexImpl.java:112)
        at com.jetbrains.python.psi.impl.PythonLanguageLevelPusher.findSdk(PythonLanguageLevelPusher.java:133)
        at com.jetbrains.python.psi.impl.PythonLanguageLevelPusher.getFileSdk(PythonLanguageLevelPusher.java:127)
        at com.jetbrains.python.psi.impl.PythonLanguageLevelPusher.getFileLanguageLevel(PythonLanguageLevelPusher.java:111)
        at com.jetbrains.python.psi.impl.PythonLanguageLevelPusher.getImmediateValue(PythonLanguageLevelPusher.java:103)
        at com.jetbrains.python.psi.impl.PythonLanguageLevelPusher.getImmediateValue(PythonLanguageLevelPusher.java:66)
        at com.intellij.openapi.roots.impl.PushedFilePropertiesUpdaterImpl.a(PushedFilePropertiesUpdaterImpl.java:218)
        at com.intellij.openapi.roots.impl.PushedFilePropertiesUpdaterImpl.findAndUpdateValue(PushedFilePropertiesUpdaterImpl.java:318)
        at com.intellij.openapi.roots.impl.PushedFilePropertiesUpdaterImpl.b(PushedFilePropertiesUpdaterImpl.java:307)
        at com.intellij.openapi.roots.impl.PushedFilePropertiesUpdaterImpl.access$1000(PushedFilePropertiesUpdaterImpl.java:63)
        at com.intellij.openapi.roots.impl.PushedFilePropertiesUpdaterImpl$11.run(PushedFilePropertiesUpdaterImpl.java:293)
        at com.intellij.openapi.application.impl.ApplicationImpl.runReadAction(ApplicationImpl.java:872)
        at com.intellij.openapi.roots.impl.PushedFilePropertiesUpdaterImpl.a(PushedFilePropertiesUpdaterImpl.java:288)
        at com.intellij.openapi.roots.impl.PushedFilePropertiesUpdaterImpl.access$700(PushedFilePropertiesUpdaterImpl.java:63)
        at com.intellij.openapi.roots.impl.PushedFilePropertiesUpdaterImpl$10$1$1.processFile(PushedFilePropertiesUpdaterImpl.java:275)
        at com.intellij.openapi.vfs.VfsUtilCore$1.visitFileEx(VfsUtilCore.java:252)
        at com.intellij.openapi.vfs.VfsUtilCore.visitChildrenRecursively(VfsUtilCore.java:267)
        at com.intellij.openapi.vfs.VfsUtilCore.visitChildrenRecursively(VfsUtilCore.java:299)
        at com.intellij.openapi.vfs.VfsUtilCore.visitChildrenRecursively(VfsUtilCore.java:299)
        at com.intellij.openapi.vfs.VfsUtilCore.visitChildrenRecursively(VfsUtilCore.java:299)
        at com.intellij.openapi.vfs.VfsUtilCore.visitChildrenRecursively(VfsUtilCore.java:299)
        at com.intellij.openapi.vfs.VfsUtilCore.iterateChildrenRecursively(VfsUtilCore.java:247)

and here is the idea.log in progress:

https://gist.github.com/ericzundel/322879568163f23fd7c6

here is the heap dump (shows lots of free space from what I can tell?) https://gist.github.com/ericzundel/52ebea0fd730065d011d

fkorotkov commented 9 years ago

Regarding project view it's because of "Show Only Loaded Files" options that is on by default in 1.3.4. See description here: https://github.com/pantsbuild/intellij-pants-plugin#plugin-features

Regarding diagnosing the performance issue. Could you please provide full output of jstack? Or at least the one for AWT-EventQueue. Could you please also add #com.twitter.intellij.pants.service.project.PantsResolver to debug categories(Help --> Configure Debug Log Settings). Unfortunately my fix is not available in IJ 14 so you need to check a few idea.log files in ~/Library/Logs/IdeaIC14.

BTW from the current stack it looks Python plugin is doing something. You can also try to disable Python Plugin and try again.

ericzundel commented 9 years ago

I think I understand what the "Show Only Loaded Files" is, but there were no files shown at all, so the project must have been corrupt?

Full jstack: https://gist.github.com/ericzundel/a5e1209e756a953fe60b

As for Help -> Configure Debug Log Settings: When I opened that dialog I had: com.twitter.intellij.pants.service.project.PantsResolver

Looks like you wanted me to turn that off by adding # in front of it, right?

Sorry, I haven't had a chance to re-run without the Python plugin yet.

fkorotkov commented 9 years ago

Yeah. You need # in front.

My understanding is that when IJ tries to update/write all project files with the newly created structure it's waiting for someone to release a write lock in AWT-EventQueue-0. The only running thread is ApplicationImpl and it's indexing unindexed files. But PythonLanguageLevelPusher from python plugin is triggered during the indexing and I'm not sure if it's a right thing.

I suggest you to take 2-3 dups with 10-20 seconds in between and send them to support@jetbrains.com. They clearly knows what is happening. And of course to verify my guess with Python plugin you might try to disable it.

ericzundel commented 9 years ago

I've turned off the debugging as you suggested. After that, I kept getting an error about "Problem validating target ..." so I did an rm -rf .idea/pants-projects in the root of my repo.

Now the project seems to import pretty quickly. (The python plugin is still on.)