How to avoid "Outdated stub in index" error?

Hello,

I have a custom EditorNotifications.Provider implementation which calls PsiClassOwner#getPackageName().
This can cause a "Outdated stub in index" error (see stack below from IDEA 2018.x, unfortunately I don't know the exact version).

I see that there are already several checks performed by the getPackageName() stack, eg:
- PsiFileImpl#getStubTree() checks: ApplicationManager.getApplication().assertReadAccessAllowed();
- StubTreeLoaderImpl#readFromVFile checks: DumbService.getInstance(project).isDumb()

So I assume the getPackageName() is relatively safe and it should return null if the file is not indexed for example.

I have also reviewed some other EditorNotifications.Provider implementations but I don't see what I am doing wrong or which check is missing in my implementation.
For example the com. intellij. psi. codeStyle. autodetect. DetectedIndentOptionsNotificationProvider is also accessing the PsiFile.

My code looks like this:

    public EditorNotificationPanel createNotificationPanel( VirtualFile file, FileEditor fileEditor ) {
        if ( !( fileEditor instanceof TextEditor ) ) {
            return null;
        }
        Editor editor = ( (TextEditor) fileEditor ).getEditor();
        Project project = editor.getProject();
        if ( project == null ) {
            return null;
        }
        PsiFile psiFile = PsiManager.getInstance( project ).findFile( file );
        if ( psiFile == null ) {
            return null;
        }
        if ( !( psiFile instanceof PsiClassOwner ) ) {
            return null;
        }
        if ( psiFile instanceof PsiCompiledFile ) {
            return null;
        }
        if ( !psiFile.isWritable() ) {
            return null;
        }
        String pkg = ((PsiClassOwner) psiFile).getPackageName();
        [...]
    }

Stack:

Outdated stub in index: 
file://c:/path/to/JavaSourceFile.java
indexed at 1522231326258 with document size 8808,
doc=DocumentImpl[file://c:/path/to/JavaSourceFile.java],
docSaved=true, wasIndexedAlready=true, queried at 1522238992830
indexed lengths={chars=8808, bytes=9031}
doc length=9122
file length=9354
cached PSI class com.intellij.psi.impl.source.PsiJavaFileImpl
projects with file: 1
java.lang.Exception
     at
com.intellij.psi.stubs.StubTreeLoaderImpl.diagnoseLengthMismatch(StubTreeLoaderImpl.java:175)
     at
com.intellij.psi.stubs.StubTreeLoaderImpl.checkLengthMatch(StubTreeLoaderImpl.java:145)
     at
com.intellij.psi.stubs.StubTreeLoaderImpl.readFromVFile(StubTreeLoaderImpl.java:113)
     at
com.intellij.psi.stubs.StubTreeLoaderImpl.readOrBuild(StubTreeLoaderImpl.java:53)
     at
com.intellij.psi.impl.source.PsiFileImpl.getStubTree(PsiFileImpl.java:652)
     at
com.intellij.psi.impl.source.PsiFileImpl.getGreenStubTree(PsiFileImpl.java:1022)
     at
com.intellij.psi.impl.source.PsiFileImpl.getGreenStub(PsiFileImpl.java:629)
     at
com.intellij.psi.impl.source.PsiJavaFileBaseImpl.getPackageName(PsiJavaFileBaseImpl.java:91)
     at
myPlugin.MyNotifierProvider.createNotificationPanel(MyNotifierProvider.java)

Thanks
Reto

1

Does this problem steadily reproducible after running "cache invalidation" action ?

1

No the problem is not reproducible. I have also just one single report for this problem.

The developer says he has excluded the source/module which contains the file (the "JavaSourceFile.java" in the error message) but the tab of this file was open.

 

0

I am having a similar problem with 

ERROR: Outdated stub in index: ...

while running automated tests.  The problem is non-deterministic in that it occurs only sometimes.  There are many tests that might trigger it, and each time I run tests, I get a few of the tests randomly failing due to the error. 

It is almost impossible to figure out what the underlying problem is, because it does not occur while running under the debugger and is non-deterministic otherwise.  We are calling 

DaemonAnalyzerTestCase#doHighlighting()

which triggers the problem. What should we look for in our code?  Is there an API we need to call before calling doHighlighting()?

Here is a full stack trace

java.lang.RuntimeException: java.util.concurrent.ExecutionException: java.lang.AssertionError: java.lang.AssertionError
at com.intellij.codeInsight.daemon.impl.DaemonCodeAnalyzerImpl.wrap(DaemonCodeAnalyzerImpl.java:968)
at com.intellij.codeInsight.daemon.impl.DaemonCodeAnalyzerImpl.runPasses(DaemonCodeAnalyzerImpl.java:368)
at com.intellij.testFramework.fixtures.impl.CodeInsightTestFixtureImpl.lambda$instantiateAndRun$3(CodeInsightTestFixtureImpl.java:224)
at com.intellij.testFramework.EdtTestUtil$Companion$runInEdtAndWait$1.invoke(EdtTestUtil.kt:29)
at com.intellij.testFramework.EdtTestUtil$Companion$runInEdtAndWait$1.invoke(EdtTestUtil.kt:27)
at com.intellij.testFramework.EdtTestUtilKt.runInEdtAndWait(EdtTestUtil.kt:40)
at com.intellij.testFramework.EdtTestUtil$Companion.runInEdtAndWait(EdtTestUtil.kt:29)
at com.intellij.testFramework.EdtTestUtil.runInEdtAndWait(EdtTestUtil.kt)
at com.intellij.testFramework.fixtures.impl.CodeInsightTestFixtureImpl.instantiateAndRun(CodeInsightTestFixtureImpl.java:224)
at com.intellij.codeInsight.daemon.DaemonAnalyzerTestCase.doHighlighting(DaemonAnalyzerTestCase.java:311)
at gw.gosu.ij.testframework.GosuFileHighlightingTestCase.checkHighlighting(GosuFileHighlightingTestCase.java:94)
at gw.gosu.ij.testframework.GosuFileHighlightingTestCase.doTestFor(GosuFileHighlightingTestCase.java:86)
at gw.gosu.ij.testframework.GosuFileHighlightingTestCase.lambda$runSingle$3(GosuFileHighlightingTestCase.java:248)
at com.intellij.testFramework.PlatformTestCase.lambda$invokeTestRunnable$19(PlatformTestCase.java:720)
at com.intellij.testFramework.PlatformTestCase.invokeTestRunnable(PlatformTestCase.java:732)
at gw.gosu.ij.testframework.GosuFileHighlightingTestCase.lambda$runSingleTest$4(GosuFileHighlightingTestCase.java:256)
at com.intellij.testFramework.EdtTestUtil$Companion$runInEdtAndWait$1.invoke(EdtTestUtil.kt:29)
at com.intellij.testFramework.EdtTestUtil$Companion$runInEdtAndWait$1.invoke(EdtTestUtil.kt:27)
at com.intellij.testFramework.EdtTestUtilKt$runInEdtAndWait$1.run(EdtTestUtil.kt:46)
at com.intellij.openapi.application.TransactionGuardImpl$2.run(TransactionGuardImpl.java:315)
at com.intellij.openapi.application.impl.LaterInvocator$1.run(LaterInvocator.java:158)
at com.intellij.openapi.application.impl.LaterInvocator$FlushQueue.runNextEvent(LaterInvocator.java:424)
at com.intellij.openapi.application.impl.LaterInvocator$FlushQueue.run(LaterInvocator.java:407)
at java.awt.event.InvocationEvent.dispatch(InvocationEvent.java:311)
at java.awt.EventQueue.dispatchEventImpl(EventQueue.java:756)
at java.awt.EventQueue.access$500(EventQueue.java:97)
at java.awt.EventQueue$3.run(EventQueue.java:709)
at java.awt.EventQueue$3.run(EventQueue.java:703)
at java.security.AccessController.doPrivileged(Native Method)
at java.security.ProtectionDomain$JavaSecurityAccessImpl.doIntersectionPrivilege(ProtectionDomain.java:80)
at java.awt.EventQueue.dispatchEvent(EventQueue.java:726)
at com.intellij.ide.IdeEventQueue.defaultDispatchEvent(IdeEventQueue.java:822)
at com.intellij.ide.IdeEventQueue._dispatchEvent(IdeEventQueue.java:650)
at com.intellij.ide.IdeEventQueue.dispatchEvent(IdeEventQueue.java:366)
at java.awt.EventDispatchThread.pumpOneEventForFilters(EventDispatchThread.java:201)
at java.awt.EventDispatchThread.pumpEventsForFilter(EventDispatchThread.java:116)
at java.awt.EventDispatchThread.pumpEventsForHierarchy(EventDispatchThread.java:105)
at java.awt.EventDispatchThread.pumpEvents(EventDispatchThread.java:101)
at java.awt.EventDispatchThread.pumpEvents(EventDispatchThread.java:93)
at java.awt.EventDispatchThread.run(EventDispatchThread.java:82)
Caused by: java.util.concurrent.ExecutionException: java.lang.AssertionError: java.lang.AssertionError
at java.util.concurrent.FutureTask.report(FutureTask.java:122)
at java.util.concurrent.FutureTask.get(FutureTask.java:192)
at com.intellij.codeInsight.daemon.impl.DaemonCodeAnalyzerImpl.waitInOtherThread(DaemonCodeAnalyzerImpl.java:429)
at com.intellij.codeInsight.daemon.impl.DaemonCodeAnalyzerImpl.lambda$runPasses$4(DaemonCodeAnalyzerImpl.java:373)
at com.intellij.codeInsight.daemon.impl.DaemonCodeAnalyzerImpl.wrap(DaemonCodeAnalyzerImpl.java:962)
... 39 more
Caused by: java.lang.AssertionError: java.lang.AssertionError
at com.intellij.testFramework.LoggedErrorProcessor.processError(LoggedErrorProcessor.java:61)
at com.intellij.testFramework.TestLogger.error(TestLogger.java:40)
at com.intellij.openapi.diagnostic.Logger.error(Logger.java:162)
at com.intellij.openapi.application.impl.ApplicationImpl$2.call(ApplicationImpl.java:344)
at java.util.concurrent.FutureTask.run(FutureTask.java:266)
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)
Caused by: java.lang.RuntimeException: java.lang.AssertionError
at com.intellij.codeInsight.daemon.impl.DaemonCodeAnalyzerImpl.lambda$waitInOtherThread$7(DaemonCodeAnalyzerImpl.java:426)
at com.intellij.openapi.application.impl.ApplicationImpl$2.call(ApplicationImpl.java:338)
... 4 more
Caused by: java.lang.AssertionError
at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:62)
at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
at java.lang.reflect.Constructor.newInstance(Constructor.java:423)
at java.util.concurrent.ForkJoinTask.getThrowableException(ForkJoinTask.java:598)
at java.util.concurrent.ForkJoinTask.get(ForkJoinTask.java:1066)
at com.intellij.concurrency.JobLauncherImpl$VoidForkJoinTask.waitForCompletion(JobLauncherImpl.java:251)
at com.intellij.codeInsight.daemon.impl.PassExecutorService.waitFor(PassExecutorService.java:590)
at com.intellij.codeInsight.daemon.impl.DaemonCodeAnalyzerImpl.lambda$waitInOtherThread$7(DaemonCodeAnalyzerImpl.java:423)
... 5 more
Caused by: java.lang.AssertionError: Outdated stub in index: file:///opt/teamcity/agent/work/568be0e82935e098/build/gosu/gosu-test/src/test/gosu/gw/specContrib/classes/property_Declarations/javaClassGosuSubClass/Errant_GosuSub_FieldVsProperty_1.gs indexed at 1549487254319 with document size 1638, doc=DocumentImpl[file:///opt/teamcity/agent/work/568be0e82935e098/build/gosu/gosu-test/src/test/gosu/gw/specContrib/classes/property_Declarations/javaClassGosuSubClass/Errant_GosuSub_FieldVsProperty_1.gs], docSaved=true, wasIndexedAlready=true, queried at 1549487254319
indexed lengths={chars=1908, bytes=1638}
doc length=1638
file length=1638
cached PSI class gw.gosu.ij.psi.impl.source.GosuPsiClassFileImpl
projects with file: [Project '/opt/teamcity/agent/work/568be0e82935e098/build/gosu/gosu-proj.ipr' gosu-proj]
at com.intellij.testFramework.LoggedErrorProcessor.processError(LoggedErrorProcessor.java:61)
at com.intellij.testFramework.TestLogger.error(TestLogger.java:40)
at com.intellij.openapi.diagnostic.Logger.error(Logger.java:162)
at com.intellij.codeInsight.daemon.impl.PassExecutorService$ScheduledPass.lambda$null$1(PassExecutorService.java:449)
at com.intellij.openapi.application.impl.ApplicationImpl.tryRunReadAction(ApplicationImpl.java:1127)
at com.intellij.codeInsight.daemon.impl.PassExecutorService$ScheduledPass.lambda$doRun$2(PassExecutorService.java:430)
at com.intellij.openapi.progress.impl.CoreProgressManager.registerIndicatorAndRun(CoreProgressManager.java:543)
at com.intellij.openapi.progress.impl.CoreProgressManager.executeProcessUnderProgress(CoreProgressManager.java:488)
at com.intellij.openapi.progress.impl.ProgressManagerImpl.executeProcessUnderProgress(ProgressManagerImpl.java:94)
at com.intellij.codeInsight.daemon.impl.PassExecutorService$ScheduledPass.doRun(PassExecutorService.java:429)
at com.intellij.codeInsight.daemon.impl.PassExecutorService$ScheduledPass.lambda$run$0(PassExecutorService.java:405)
at com.intellij.openapi.application.impl.ReadMostlyRWLock.executeByImpatientReader(ReadMostlyRWLock.java:143)
at com.intellij.openapi.application.impl.ApplicationImpl.executeByImpatientReader(ApplicationImpl.java:229)
at com.intellij.codeInsight.daemon.impl.PassExecutorService$ScheduledPass.run(PassExecutorService.java:403)
at com.intellij.concurrency.JobLauncherImpl$VoidForkJoinTask$1.exec(JobLauncherImpl.java:170)
at java.util.concurrent.ForkJoinTask.doExec(ForkJoinTask.java:289)
at java.util.concurrent.ForkJoinPool$WorkQueue.runTask(ForkJoinPool.java:1056)
at java.util.concurrent.ForkJoinPool.runWorker(ForkJoinPool.java:1692)
at java.util.concurrent.ForkJoinWorkerThread.run(ForkJoinWorkerThread.java:157)
0

@Bgoldberg Do the tests have clear caches every time? (If caches/indices are reused between test runs) This problem may happen if indices were not updated due to events about file changes: forced termination of tests, absence of explicit virtual file refresh on used files (our tests were used to skip this costly operation) or even bugs in indices itself that were fixed between IJ 2017.3 and IJ 2018.1

0

@Maxim Mossienko

Our tests use this logic:

// we don't want to change anything, so set altered text and then return back the original text
setDocumentText(document, text);
try {
GosuExpectedHighlightingData highlightingData = collectExpectedHighlighting(gosuFilePath, text);
checkHighlighting(highlightingData);
} finally {
setDocumentText(document, origText);
}

where setDocumentText is

private void setDocumentText(final Document document, final String text) {
if (!document.getText().equals(text)) {
runWriteCommandAction(getProject(), () -> {
document.setText(text);
FileDocumentManager.getInstance().saveDocument(document);
});
}
}

At what point should we clear caches? Would adding

getFile().clearCaches()

in the finally clause above help?

Thanks.

0

The outdated stub is apparently in the index, so do I have to call some code to make sure the changes are indexed correctly?  Perhaps the indexing thread is either not running or not keeping up with the test.

0

After changing document and saving it your code need to perform commit of document text to AST used by background error detection, indices, etc by calling  PsiDocumentManager.getInstance(project).commitDocument(document);

0

I seem to get various spurious exceptions when debugging my test code.  It looks like the test environment does not clean up properly.  I am trying to work around this problem to get to the underlying issue.

0

We are also facing with the problem accidentally. Is there any recommendations how to avoid it?

0

It is annoying because it is non-deterministic.  I imagine that some of our tests are somehow not following some contract correctly, but since it occurs most often during the shutdown after the test, we don't know where to look or what to look for.  Can you provide some hints or documentation?

0

At this amount of details we can repeat only generic recommendations: first recommendation and second recommendation from this post.

Please clean test caches and attach all log files after encountering the problem.

0

Both of those links are to the same page.

0

Thanks for spotting. I fixed the links, just in case links point to my previous comments on this page.

0

FYI:

After two years, I have received a second report of that issue. Here is the stack (reporter has not mentioned the IDEA version):

{code}

Outdated stub in index: file://c:/path/to/JavaSourceFile.java indexed at 1586879831076 with document size 42241,
doc=DocumentImpl[file://c:/path/to/JavaSourceFile.java], docSaved=true, wasIndexedAlready=true, queried at 1591601035485
indexed lengths={chars=42241, bytes=43175}
doc length=42190
file length=43125
cached PSI class com.intellij.psi.impl.source.PsiJavaFileImpl
projects with file: 1

java.lang.Exception
at com.intellij.psi.stubs.StubTreeLoaderImpl.diagnoseLengthMismatch(StubTreeLoaderImpl.java:180)
at com.intellij.psi.stubs.StubTreeLoaderImpl.checkLengthMatch(StubTreeLoaderImpl.java:150)
at com.intellij.psi.stubs.StubTreeLoaderImpl.readFromVFile(StubTreeLoaderImpl.java:118)
at com.intellij.psi.stubs.StubTreeLoaderImpl.readOrBuild(StubTreeLoaderImpl.java:53)
at com.intellij.psi.impl.source.PsiFileImpl.getStubTree(PsiFileImpl.java:610)
at com.intellij.psi.impl.source.PsiFileImpl.getGreenStubTree(PsiFileImpl.java:933)
at com.intellij.psi.impl.source.PsiFileImpl.getGreenStub(PsiFileImpl.java:586)
at com.intellij.psi.impl.source.PsiJavaFileBaseImpl.getPackageName(PsiJavaFileBaseImpl.java:78)
at ch.abacus.idea.statics.ToBeReviewedCache.find(ToBeReviewedCache.java:84)
at ch.abacus.idea.statics.ToBeReviewedNotifierProvider.createNotificationPanel(ToBeReviewedNotifierProvider.java:97)
at ch.abacus.idea.statics.ToBeReviewedNotifierProvider.createNotificationPanel(ToBeReviewedNotifierProvider.java:48)
at com.intellij.ui.EditorNotifications$Provider.createNotificationPanel(EditorNotifications.java:37)
at com.intellij.ui.EditorNotificationsImpl.calcNotificationUpdates(EditorNotificationsImpl.java:117)
at com.intellij.ui.EditorNotificationsImpl.lambda$null$0(EditorNotificationsImpl.java:96)
at com.intellij.openapi.application.impl.NonBlockingReadActionImpl$Submission.insideReadAction(NonBlockingReadActionImpl.java:144)
at com.intellij.openapi.application.impl.NonBlockingReadActionImpl$Submission.lambda$null$1(NonBlockingReadActionImpl.java:118)
at com.intellij.openapi.application.impl.ApplicationImpl.tryRunReadAction(ApplicationImpl.java:1166)
at com.intellij.openapi.progress.util.ProgressIndicatorUtils.lambda$runInReadActionWithWriteActionPriority$0(ProgressIndicatorUtils.java:68)
at com.intellij.openapi.progress.util.ProgressIndicatorUtils.lambda$runWithWriteActionPriority$1(ProgressIndicatorUtils.java:121)
at com.intellij.openapi.progress.impl.CoreProgressManager.lambda$runProcess$2(CoreProgressManager.java:164)
at com.intellij.openapi.progress.impl.CoreProgressManager.registerIndicatorAndRun(CoreProgressManager.java:586)
at com.intellij.openapi.progress.impl.CoreProgressManager.executeProcessUnderProgress(CoreProgressManager.java:532)
at com.intellij.openapi.progress.impl.ProgressManagerImpl.executeProcessUnderProgress(ProgressManagerImpl.java:86)
at com.intellij.openapi.progress.impl.CoreProgressManager.runProcess(CoreProgressManager.java:151)
at com.intellij.openapi.progress.util.ProgressIndicatorUtils.runWithWriteActionPriority(ProgressIndicatorUtils.java:110)
at com.intellij.openapi.progress.util.ProgressIndicatorUtils.runInReadActionWithWriteActionPriority(ProgressIndicatorUtils.java:68)
at com.intellij.openapi.application.impl.NonBlockingReadActionImpl$Submission.lambda$transferToBgThread$2(NonBlockingReadActionImpl.java:118)
at com.intellij.util.concurrency.BoundedTaskExecutor.doRun(BoundedTaskExecutor.java:220)
at com.intellij.util.concurrency.BoundedTaskExecutor.access$100(BoundedTaskExecutor.java:26)
at com.intellij.util.concurrency.BoundedTaskExecutor$2.lambda$run$0(BoundedTaskExecutor.java:198)
at com.intellij.util.ConcurrencyUtil.runUnderThreadName(ConcurrencyUtil.java:224)
at com.intellij.util.concurrency.BoundedTaskExecutor$2.run(BoundedTaskExecutor.java:194)
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)

{code}

0

请先登录再写评论。