As of 2021.3, Tests hang when invoked from command line, but they run fine from IDE

Answered

Created March 09, 2022 20:01

I'm having trouble with some JUnit tests hanging forever (well over 24 hours) when I invoke them through the Gradle command line. If I run the same tests directly from IJ2021.3.2 in the IDE, they complete successfully in about 15 minutes.

NOTE: In IJ 2021.1.3, the tests ran fine under the command line and the IDE. So it looks like some change in 2021.2 or 2021.3 caused the problem.

I need these tests to run from a TeamCity job, automatically, upon commit, so I need to get them so they can run from the command line without hanging.

DIAGNOSIS, SO FAR

I attached a remote debug to the command line test run, and found the call in my code that never returns:

FindInProjectUtil.findUsages(model, getProject(), //<<HERE
  usageInfo -> {
    usages.add(usageInfo); // Never get here
    return false;
  },
  new FindUsagesProcessPresentation(FindInProjectUtil.setupViewPresentation(true, model)));

By pressing pause on the remote debug session, I get a stack trace that differs in the last few calls each time, but is basically stuck in FindInProjectUtil#findUsages() which is stuck in the findUsages() at line 225 doing

ProgressManager.getInstance().runProcess(runnable, new EmptyProgressIndicator());

The stack trace typically looks like this:

sleep:-1, Thread (java.lang)
sleep:18, TimeoutUtil (com.intellij.util)
lambda$processDequeOnAllThreads$1:69, FilesScanExecutor (com.intellij.openapi.roots.impl)
run:-1, 242882974 (com.intellij.openapi.roots.impl.FilesScanExecutor$$Lambda$1384)
runOnAllThreads:42, FilesScanExecutor (com.intellij.openapi.roots.impl)
processDequeOnAllThreads:59, FilesScanExecutor (com.intellij.openapi.roots.impl)
processFilesInScope:397, FindInProjectTask (com.intellij.find.impl)
findUsages:161, FindInProjectTask (com.intellij.find.impl)
lambda$findUsages$0:223, FindInProjectUtil (com.intellij.find.impl)
run:-1, 1990610061 (com.intellij.find.impl.FindInProjectUtil$$Lambda$1369)
lambda$runProcess$2:188, CoreProgressManager (com.intellij.openapi.progress.impl)
run:-1, 1512775028 (com.intellij.openapi.progress.impl.CoreProgressManager$$Lambda$682)
lambda$executeProcessUnderProgress$12:624, CoreProgressManager (com.intellij.openapi.progress.impl)
compute:-1, 577605263 (com.intellij.openapi.progress.impl.CoreProgressManager$$Lambda$687)
registerIndicatorAndRun:698, CoreProgressManager (com.intellij.openapi.progress.impl)
computeUnderProgress:646, CoreProgressManager (com.intellij.openapi.progress.impl)
executeProcessUnderProgress:623, CoreProgressManager (com.intellij.openapi.progress.impl)
executeProcessUnderProgress:66, ProgressManagerImpl (com.intellij.openapi.progress.impl)
runProcess:175, CoreProgressManager (com.intellij.openapi.progress.impl)
findUsages:225, FindInProjectUtil (com.intellij.find.impl)
findUsages:215, FindInProjectUtil (com.intellij.find.impl)
findFileWithAnyMarker:249, GosuMultiFileTestCase (gw.gosu.ij.testframework) << My call, as shown above
findFileWithMarkers:224, GosuMultiFileTestCase (gw.gosu.ij.testframework)
configureByDirectory:184, GosuMultiFileTestCase (gw.gosu.ij.testframework)
doTest:70, GosuMultiFileTestCase (gw.gosu.ij.testframework)
doTest:52, GosuMultiFileTestCase (gw.gosu.ij.testframework)
doTest:108, GosuGenerateConstructorTest (gw.gosu.ij.codeInsight)
doTest:104, GosuGenerateConstructorTest (gw.gosu.ij.codeInsight)
testNoMoreConstructorsCanBeGenerated:64, GosuGenerateConstructorTest (gw.gosu.ij.codeInsight)
invoke0:-1, NativeMethodAccessorImpl (jdk.internal.reflect)
invoke:62, NativeMethodAccessorImpl (jdk.internal.reflect)
invoke:43, DelegatingMethodAccessorImpl (jdk.internal.reflect)
invoke:566, Method (java.lang.reflect)
runTest:176, TestCase (junit.framework)
lambda$runBare$11:533, UsefulTestCase (com.intellij.testFramework)
run:-1, 1190617061 (com.intellij.testFramework.UsefulTestCase$$Lambda$52)
runTestRunnable:454, UsefulTestCase (com.intellij.testFramework)
lambda$runTestRunnable$27:695, HeavyPlatformTestCase (com.intellij.testFramework)
run:-1, 1103978440 (com.intellij.testFramework.HeavyPlatformTestCase$$Lambda$1301)
lambda$runAndWait$2:115, WriteAction (com.intellij.openapi.application)
compute:-1, 477956128 (com.intellij.openapi.application.WriteAction$$Lambda$569)
runWriteActionWithClass:935, ApplicationImpl (com.intellij.openapi.application.impl)
runWriteAction:961, ApplicationImpl (com.intellij.openapi.application.impl)
computeAndWait:134, WriteAction (com.intellij.openapi.application)
computeAndWait:128, WriteAction (com.intellij.openapi.application)
runAndWait:114, WriteAction (com.intellij.openapi.application)
runTestRunnable:695, HeavyPlatformTestCase (com.intellij.testFramework)
lambda$runBareImpl$24:618, HeavyPlatformTestCase (com.intellij.testFramework)
run:-1, 1809039832 (com.intellij.testFramework.HeavyPlatformTestCase$$Lambda$103)
lambda$runInEdtAndWait$1:40, EdtTestUtil (com.intellij.testFramework)
run:-1, 263199584 (com.intellij.testFramework.EdtTestUtil$$Lambda$104)
dispatch:303, InvocationEvent (java.awt.event)
dispatchEventImpl:770, EventQueue (java.awt)
run:721, EventQueue$4 (java.awt)
run:715, EventQueue$4 (java.awt)
doPrivileged:-1, AccessController (java.security)
doIntersectionPrivilege:85, ProtectionDomain$JavaSecurityAccessImpl (java.security)
dispatchEvent:740, EventQueue (java.awt)
dispatchEvent:407, IdeEventQueue (com.intellij.ide)
pumpOneEventForFilters:203, EventDispatchThread (java.awt)
pumpEventsForFilter:124, EventDispatchThread (java.awt)
pumpEventsForHierarchy:113, EventDispatchThread (java.awt)
pumpEvents:109, EventDispatchThread (java.awt)
pumpEvents:101, EventDispatchThread (java.awt)
run:90, EventDispatchThread (java.awt)

One interesting thing is the FileScanExecutor#runOnAllThreads() call, but that is just a wild guess.

That's as far as I have gotten. If I try to follow the code that is stuck by stepping through it, it just goes through a ridiculous number of calls, looking at every character of every file in the test, one by one.

How can I debug this?

12 comments

Bob Goldberg

Created March 09, 2022 20:29

In case it helps, here's what my method in GosuMultiFileTestCase is doing. It is looking for any of several marker characters.

@Nullable
private VirtualFile findFileWithAnyMarker(@NotNull VirtualFile rootDir, String... markers) {
  checkArgument(markers.length > 0, "Must be at least one marker specified");

  final StringBuilder regexToFind = new StringBuilder();
  for (String marker : markers) {
    checkArgument(!marker.isEmpty(), "Marker cannot be empty");
    if (regexToFind.length() > 0) {
      regexToFind.append("|");
    }
    regexToFind.append(Pattern.quote(marker));
  }

  final FindModel model = new FindModel();
  model.setStringToFind(regexToFind.toString());
  model.setRegularExpressions(true);
  model.setDirectoryName(rootDir.getCanonicalPath());
  model.setWithSubdirectories(true);
  model.setProjectScope(false);

  final List<UsageInfo> usages = new ArrayList<>();
  FindInProjectUtil.findUsages(model, getProject(),
    usageInfo -> {
      usages.add(usageInfo);
      return false;
    },
    new FindUsagesProcessPresentation(FindInProjectUtil.setupViewPresentation(true, model)));

  return !usages.isEmpty() ? usages.get(0).getVirtualFile() : null;
}

Yann Cebron

Created March 10, 2022 15:30

Please try
1) pass rootDir.getPresentableUrl() for setDirectoryName()

2) or model.setCustomScope() with com.intellij.psi.search.GlobalSearchScopes#directoryScope(Project, rootDir, true)

Bob Goldberg

Created March 11, 2022 02:26

1) rootDir.getPresentableUrl() and rootDir.getCanonicalPath() return identical strings, so that didn't help.

2) I am guessing you meant something like this:

@Nullable
  private VirtualFile findFileWithAnyMarker(@NotNull VirtualFile rootDir, String... markers) {
    checkArgument(markers.length > 0, "Must be at least one marker specified");

    final StringBuilder regexToFind = new StringBuilder();
    for (String marker : markers) {
      checkArgument(!marker.isEmpty(), "Marker cannot be empty");
      if (regexToFind.length() > 0) {
        regexToFind.append("|");
      }
      regexToFind.append(Pattern.quote(marker));
    }

    final FindModel model = new FindModel();
    model.setStringToFind(regexToFind.toString());
    model.setRegularExpressions(true);
//    model.setDirectoryName(rootDir.getCanonicalPath());
    model.setDirectoryName(rootDir.getPresentableUrl()); // JB Yann Cebron suggests this instead.
    model.setWithSubdirectories(true);
    model.setProjectScope(false);
    // YB Yann Cebron suggests the following:
    model.setCustomScope(GlobalSearchScopes.directoryScope(myProject, rootDir, true));
    model.setCaseSensitive(true);

    final List<UsageInfo> usages = new ArrayList<>();
    FindInProjectUtil.findUsages(model, getProject(), // << Still stuck in findUsages
      usageInfo -> {
        usages.add(usageInfo);
        return false;
      },
      new FindUsagesProcessPresentation(FindInProjectUtil.setupViewPresentation(true, model))
    );

    return !usages.isEmpty() ? usages.get(0).getVirtualFile() : null;
  }

That didn't avoid a hang, either.

I see a problem in FilesScanExecutor, in the loop starting at line 62, where idleCount.get() gets stuck at 11, and runnersCount.get() gets stuck at 12. This seems to be why it's hanging. I don't see where runnersCount is getting decremented anywhere. idleCount gets decremented if idle is true, but execution goes through this loop forever and idleCount is not decremented.

How are these method-local variables ever supposed to change, once they are not the same and the loop is entered?

Gregory Shrago

Created March 19, 2022 13:16

Please try the latest IDEA 2022.1 EAP (EAP6 build 221.5080.9). The code in FilesScanExecutor#processDequeOnAllThreads is a bit different there. Let's check if it solves the problem.

Bob Goldberg

Created March 25, 2022 00:45

I'm still trying to upgrade to IDEA 2022.1 EAP to try out your suggestion. It's not so easy. It seems I have to download IDEA 2022.1 EAP or else my IDE code won't even compile (under 2021.3.2). That's a bit strange. And then Gradle is having fits because it wants some stupid Gradle property set to something that tells it to fetch the EAP from the JetBrains website. For a true release, I just set it to the full 3-number release, but for an EA I have to set it to something different, because there's no third number. Is it 2022.1.EA? 2022.1-EA? Gradle gives no clear error messages that actually tell you where the problem is, or what it is.

Gregory Shrago

Created March 25, 2022 12:50

Please try 221.5080-EAP-CANDIDATE-SNAPSHOT

Bob Goldberg

Created March 29, 2022 02:38

Thanks.

I tried that, and under it my hanging tests still seem to hang. I still get stuck in that loop, with runnersCount == 12 and idleCount == 11.

Gregory Shrago

Created March 30, 2022 16:03

I'd like to try and reproduce the problem. Is it possible?

Bob Goldberg

Created March 30, 2022 21:48

It is possible, but I'm not sure how best to do it. I could zip up my workspace, but chances are that things would go wrong because of configuration problems and expected things not found. However, it is worth a try. Where should I put the zip file so you can get it?

Gregory Shrago

Created March 30, 2022 22:26

Please upload the file at https://uploads.jetbrains.com/ and share the "upload id" in IDEA-291283 I've created for this case.

Bob Goldberg

Created March 31, 2022 22:59

I did this yesterday. Is it what you wanted?

Gregory Shrago

Created April 01, 2022 10:41

Yes, thanks! Let's proceed in the ticket.

Please sign in to leave a comment.