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

13 comments
Comment actions Permalink

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

0
Comment actions Permalink

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
Comment actions Permalink

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
Comment actions Permalink

@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
Comment actions Permalink

@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
Comment actions Permalink

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
Comment actions Permalink

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
Comment actions Permalink

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
Comment actions Permalink

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

0
Comment actions Permalink

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
Comment actions Permalink

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
Comment actions Permalink

Both of those links are to the same page.

0
Comment actions Permalink

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

0

Please sign in to leave a comment.