ArrayIndexOutOfBoundsException in build options dialog when Local Only checked

[Scott Wells]

This was reported by Pengyang Liu via email. He's seeing the following error when opening the build options dialog for deployment, specifically with Local Only checked:

2020-05-14 14:11:02,601 [  34164]   WARN - .IlluminatedCloudExceptionUtil - 3 > 2
java.lang.ArrayIndexOutOfBoundsException: 3 > 2
    at java.base/java.util.Vector.insertElementAt(Vector.java:619)
    at java.desktop/javax.swing.tree.DefaultMutableTreeNode.insert(DefaultMutableTreeNode.java:192)
    at com.intellij.util.ui.tree.TreeUtil.addChildrenTo(TreeUtil.java:415)
    at com.intellij.util.ui.tree.TreeUtil.sortChildren(TreeUtil.java:409)
    at com.intellij.util.ui.tree.TreeUtil.sortRecursively(TreeUtil.java:395)
    at com.intellij.util.ui.tree.TreeUtil.sortRecursively(TreeUtil.java:398)
    at com.intellij.util.ui.tree.TreeUtil.sortRecursively(TreeUtil.java:398)
    at com.intellij.util.ui.tree.TreeUtil.sort(TreeUtil.java:391)
    at com.illuminatedcloud.intellij.builder.BuildOptionsDialog$2.run(SourceFile:1769)
    at com.intellij.openapi.progress.impl.CoreProgressManager$TaskRunnable.run(CoreProgressManager.java:932)
    at com.intellij.openapi.progress.impl.CoreProgressManager$4.run(CoreProgressManager.java:482)
    at com.intellij.openapi.progress.impl.ProgressRunner.lambda$new$0(ProgressRunner.java:77)
    at com.intellij.openapi.progress.impl.ProgressRunner.lambda$null$3(ProgressRunner.java:233)
    at com.intellij.openapi.progress.impl.CoreProgressManager.lambda$runProcess$2(CoreProgressManager.java:166)
    at com.intellij.openapi.progress.impl.CoreProgressManager.registerIndicatorAndRun(CoreProgressManager.java:627)
    at com.intellij.openapi.progress.impl.CoreProgressManager.executeProcessUnderProgress(CoreProgressManager.java:572)
    at com.intellij.openapi.progress.impl.ProgressManagerImpl.executeProcessUnderProgress(ProgressManagerImpl.java:61)
    at com.intellij.openapi.progress.impl.CoreProgressManager.runProcess(CoreProgressManager.java:153)
    at com.intellij.openapi.progress.impl.ProgressRunner.lambda$submit$4(ProgressRunner.java:233)
    at java.base/java.util.concurrent.CompletableFuture$AsyncSupply.run(CompletableFuture.java:1700)
    at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
    at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
    at java.base/java.lang.Thread.run(Thread.java:834)

I'm going to use this issue to debug the issue, specifically as a placeholder to get additional diagnostic information.

[Scott Wells]

I'm attaching a version of 2.1.2.0 that includes some additional debug logging just before the tree is sorted. Please download it (but don't extract it) and install it using Settings/Preferences>Plugins>Install plugin from disk (under the gear drop-down menu). Once installed, please add the following to Help>Diagnostic Tools>Debug Log Settings:

#com.illuminatedcloud.intellij.builder.BuildOptionsDialog

Note that the leading # is important.

Then please reproduce the issue by toggling Local Only on and then off so I can see the tree both ways.

Once that's done, I'll need to see the full idea.log (or potentially multiple idea.log* files if they roll from the extensive logging). Feel free to redact anything you'd like and then email it/them to [e-mail].

[Justin Julicher]

HI @Scott Wells

‌

I was having the same issue as Pengyang Liu and tried the attached version and it seems to have issues. I’ve attached my logs - it seems to have an issue with custom labels possibly - there was this line in the log:

‌

2020-05-18 15:24:37,375 [ 945775]   WARN - l.IlluminatedCloudMetadataUtil - Failed to get the metadata describe for module Cortex-GitFlow, file /home/justin/WebstormProjects/Cortex-GitFlow/src/labels/CustomLabels.labels: null 

‌

‌

Anyway I’ll let you look at my logs too.

‌

‌

‌

[Scott Wells]

Thanks for the log, Justin. I also received one from Peng. Hopefully between the two I can reproduce and fix the issue quickly today. I'll keep you both posted here.

[Scott Wells]

Justin, you mentioned that the attached version seems to have issues. What do you mean exactly? The log entry you included is benign. I've changed the way it's logged, but it degrades gracefully to the correct metadata information for that file. However, I don't see the new debug logging in your provided logs. I'm looking for an entry that starts with The constructed tree is ....

Would you mind getting me a log with that info? Unfortunately right now I'm not seeing the problem in the logs provided by you and Peng. Thanks!

[Justin Julicher]

Hi Scott

Yeah when I tried to bring up the deploy dialog it would keep hanging on me. I tried 3 times and had to kill webstorm as the cancel button (even though I could click it) did nothing. The logs I provided were from that process. In the end I had to revert to 2.1.19 which worked fine.

‌

‌

[Justin Julicher]

HI Scott, I probably wasn’t patient enough with the process -it’s writing a huge amount of lines to the logs - is there anyway to buffer that to speed it up? I have an NVMe drive in my laptop and it shouldn’t take this long to write out logs right? I’m talking a good 10-15 minutes here - I also have a i7-8750h processor so it’s not a cpu issue……

‌

‌

[Scott Wells]

Justin, when you enable debug logging in BuildOptionsDialog it spits a TON of stuff to the log, though I wouldn't ever expect it to take 10-15 minutes to write that unless you had millions of metadata objects. I have a project with ~30K metadata objects and with all of that debug logging enabled, that dialog opens in a few seconds. Something else must be going on. Do you seem similar behavior if you remove that debug logging line, or does that open quickly but show the 3 > 2 error?

[Justin Julicher]

No weirdly I didn’t see the x < y error (Mine was 6 > 5) when I managed to get through the dialog this time.

With debug off and the metadata cached the dialog comes up almost instantly

I’ve installed your new debug version and now I can’t replicate the issue anymore so for me I guess it’s resolved.

I found the log file with your line in it from yesterday so I’ll upload that and hopefully that will give you some more detail.

‌

thanks

‌

[Scott Wells]

Thanks, Justin. I'll take a look tomorrow and continue to work with Peng since he can reproduce this reliably. If you do see it again, just let me know.

[Mark Lengwin]

Scott, I am consistently seeing the same issue with a new installation and can assist as needed.

[Scott Wells]

Hi, Mark. That would be much appreciated. I've pinned the response that specifies how to install the attached build and get the desired debug log. If you could do that, hopefully that will provide the information I need to diagnose and fix this.

[Scott Wells]

Here's another build where I've implemented my own recursive sorting of the tree with additional diagnostic logging. Can you please install this and try to reproduce the issue. No additional debug logging config is required as it logs at the warning level if an unexpected state is encountered. Regardless of whether it seems to fix the problem or not, can you please provide the resulting idea.log file for review?

[Mark Lengwin]

Scott, I didn’t get the error with the latest build. I will send the logs shortly, and they include use (toggling local server) with the prior build. Thanks.

[Pengyang Liu]

Hi Scott,

same for me. The new build seems to have resolved the issue. I just sent you the logs via mail. Thanks a lot.

[Scott Wells]

Thanks for the update, Mark and Peng. Let me review the logs you've provided on the new build as the update included in the new build avoids the plugin SDK mechanism for sorting the tree by using one I wrote, and instead of throwing an exception when unexpected nodes are encountered, I log the situation. I want to see if there is still something wrong with the constructed tree so that I can resolve that. Either way I'll plan to include a variation of this in the next release which will likely come out tomorrow. I'll keep you posted on further progress here.

[Scott Wells]

I just reviewed both of your logs and don't see any issues while sorting the tree. Perhaps there's a bug in the plugin SDK's own recursive tree sorter. If you do find something to be missing from the checkbox tree or any other potentially weird side-effects, please let me know, but I'm going to plan to move forward with the fix (and corresponding diagnostic improvements) in the attached build for the next official build. Thanks so much for helping to corner this!

[Scott Wells]

Delivered in 2.1.2.1.