Skip to content

ProtocolNotBoundException exception when importing libraries in IDEA #1433

Closed
#1536
Closed
ProtocolNotBoundException exception when importing libraries in IDEA#1433
#1536
Assignees
Domonion
Labels
comp-rdIssue is related RDctg-bugIssue is a bug
Milestone
2022.12 Release

Description

@alisevych
alisevych
opened on Nov 28, 2022

Description

The following exception has fallen into IDEA when Generate tests action had been initiated before import libraries and indexing in IDEA process finished:
com.jetbrains.rd.framework.base.ProtocolNotBoundException: Server.EngineProcessModel.obtainClassId::<<unbound>> is not bound to a protocol

To Reproduce

  1. The following settings.properties was used:

logConcreteExecutionErrors=true instrumentedProcessLogLevel=Debug

  1. Run the 'UTBotJava' project in IntelliJ Idea
  2. Install one of the latest plugins built from main
  3. Checkout main version from 3 days ago (to initiate import and indexing process lasting long)
  4. Start test generation for 1-2 samples (static mocking was selected)

Expected behavior

No exception is supposed to fall down to IDE.

Actual behavior

ProtocolNotBoundException: Server.EngineProcessModel.obtainClassId::<> is not bound to a protocol
Details com.jetbrains.rd.framework.base.ProtocolNotBoundException: Server.EngineProcessModel.obtainClassId::<> is not bound to a protocol at com.jetbrains.rd.framework.base.RdBindableBase.nb(RdBindableBase.kt:52) at com.jetbrains.rd.framework.base.RdBindableBase.getProtocol(RdBindableBase.kt:36) at com.jetbrains.rd.framework.impl.RdCall.createResponseScheduler(RdTask.kt:264) at com.jetbrains.rd.framework.impl.RdCall.startSuspending(RdTask.kt:258) at com.jetbrains.rd.framework.IRdCall$DefaultImpls.startSuspending(TaskInterfaces.kt:167) at com.jetbrains.rd.framework.impl.RdCall.startSuspending(RdTask.kt:186) at com.jetbrains.rd.framework.IRdCall$DefaultImpls.startSuspending$default(TaskInterfaces.kt:167) at org.utbot.rd.UtRdUtilKt$startBlocking$1.invokeSuspend(UtRdUtil.kt:30) at kotlin.coroutines.jvm.internal.BaseContinuationImpl.resumeWith(ContinuationImpl.kt:33) at kotlinx.coroutines.DispatchedTask.run(DispatchedTask.kt:106) at kotlinx.coroutines.EventLoopImplBase.processNextEvent(EventLoop.common.kt:284) at kotlinx.coroutines.BlockingCoroutine.joinBlocking(Builders.kt:85) at kotlinx.coroutines.BuildersKt__BuildersKt.runBlocking(Builders.kt:59) at kotlinx.coroutines.BuildersKt.runBlocking(Unknown Source) at kotlinx.coroutines.BuildersKt__BuildersKt.runBlocking$default(Builders.kt:38) at kotlinx.coroutines.BuildersKt.runBlocking$default(Unknown Source) at org.utbot.rd.UtRdUtilKt.startBlocking(UtRdUtil.kt:30) at org.utbot.intellij.plugin.process.EngineProcess.obtainClassId(EngineProcess.kt:200) at org.utbot.intellij.plugin.generator.UtTestsDialogProcessor$createTests$1$1$run$1$2.compute(UtTestsDialogProcessor.kt:173) at org.utbot.intellij.plugin.generator.UtTestsDialogProcessor$createTests$1$1$run$1$2.compute(UtTestsDialogProcessor.kt:171) at com.intellij.openapi.project.DumbService.lambda$runReadActionInSmartMode$0(DumbService.java:113) at com.intellij.openapi.project.DumbService.lambda$runReadActionInSmartMode$1(DumbService.java:157) at com.intellij.openapi.application.impl.ApplicationImpl.runReadAction(ApplicationImpl.java:941) at com.intellij.openapi.application.ReadAction.compute(ReadAction.java:68) at com.intellij.openapi.project.DumbService.runReadActionInSmartMode(DumbService.java:150) at com.intellij.openapi.project.DumbService.runReadActionInSmartMode(DumbService.java:113) at org.utbot.intellij.plugin.generator.UtTestsDialogProcessor$createTests$1$1.run(UtTestsDialogProcessor.kt:171) at com.intellij.openapi.progress.impl.CoreProgressManager.startTask(CoreProgressManager.java:442) at com.intellij.openapi.progress.impl.ProgressManagerImpl.startTask(ProgressManagerImpl.java:114) at com.intellij.openapi.progress.impl.CoreProgressManager.lambda$runProcessWithProgressAsynchronously$5(CoreProgressManager.java:493) at com.intellij.openapi.progress.impl.ProgressRunner.lambda$submit$3(ProgressRunner.java:252) at com.intellij.openapi.progress.impl.CoreProgressManager.lambda$runProcess$2(CoreProgressManager.java:188) at com.intellij.openapi.progress.impl.CoreProgressManager.lambda$executeProcessUnderProgress$12(CoreProgressManager.java:608) at com.intellij.openapi.progress.impl.CoreProgressManager.registerIndicatorAndRun(CoreProgressManager.java:683) at com.intellij.openapi.progress.impl.CoreProgressManager.computeUnderProgress(CoreProgressManager.java:639) at com.intellij.openapi.progress.impl.CoreProgressManager.executeProcessUnderProgress(CoreProgressManager.java:607) at com.intellij.openapi.progress.impl.ProgressManagerImpl.executeProcessUnderProgress(ProgressManagerImpl.java:60) at com.intellij.openapi.progress.impl.CoreProgressManager.runProcess(CoreProgressManager.java:175) at com.intellij.openapi.progress.impl.ProgressRunner.lambda$submit$4(ProgressRunner.java:252) at java.base/java.util.concurrent.CompletableFuture$AsyncSupply.run(CompletableFuture.java:1768) at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136) at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) at java.base/java.util.concurrent.Executors$PrivilegedThreadFactory$1$1.run(Executors.java:702) at java.base/java.util.concurrent.Executors$PrivilegedThreadFactory$1$1.run(Executors.java:699) at java.base/java.security.AccessController.doPrivileged(AccessController.java:399) at java.base/java.util.concurrent.Executors$PrivilegedThreadFactory$1.run(Executors.java:699) at java.base/java.lang.Thread.run(Thread.java:833)

Visual proofs (screenshots, logs, images)

idea.log
Details 2022-11-28 16:10:10,487 [1609496] INFO - STDOUT - Locked 2022-11-28 16:10:10,567 [1609576] INFO - STDOUT - Engine process started with PID = 16012 2022-11-28 16:10:10,569 [1609578] INFO - STDOUT - Engine process log file - C:\Users\lWX1182794\AppData\Local\Temp\UTBot\rdEngineProcessLogs\28-11-2022_16-10-10.log 2022-11-28 16:10:10,573 [1609582] INFO - STDOUT - RdCoroutineHost overridden 2022-11-28 16:10:15,660 [1614669] INFO - #c.j.p.intellij-plugin - [3, source=INIT] ProjectDataProvider#fetchInfoFor() - Failed obtaining data for 8 dependencies 2022-11-28 16:11:17,728 [1676737] WARN - #c.i.u.x.Binding - no accessors for org.jetbrains.idea.perforce.perforce.ConnectionId 2022-11-28 16:11:17,759 [1676768] INFO - #c.i.c.ComponentStoreImpl - Saving Project(name=utbot, containerState=COMPONENT_CREATED, componentStore=C:\Users\lWX1182794\UTBotJava)GradleLocalSettings took 11 ms 2022-11-28 16:12:17,919 [1736928] INFO - STDOUT - ServerSocket: start terminating lifetime 2022-11-28 16:12:18,434 [1737443] INFO - STDOUT - ServerSocket: termination finished

2022-11-28 16:12:56,772 [1775781] INFO - STDOUT - Unlocked
2022-11-28 16:12:56,875 [1775884] SEVERE - #c.i.o.p.Task - Server.EngineProcessModel.obtainClassId::<> is not bound to a protocol
com.jetbrains.rd.framework.base.ProtocolNotBoundException: Server.EngineProcessModel.obtainClassId::<> is not bound to a protocol
at com.jetbrains.rd.framework.base.RdBindableBase.nb(RdBindableBase.kt:52)
at com.jetbrains.rd.framework.base.RdBindableBase.getProtocol(RdBindableBase.kt:36)
at com.jetbrains.rd.framework.impl.RdCall.createResponseScheduler(RdTask.kt:264)
at com.jetbrains.rd.framework.impl.RdCall.startSuspending(RdTask.kt:258)
at com.jetbrains.rd.framework.IRdCall$DefaultImpls.startSuspending(TaskInterfaces.kt:167)
at com.jetbrains.rd.framework.impl.RdCall.startSuspending(RdTask.kt:186)
at com.jetbrains.rd.framework.IRdCall$DefaultImpls.startSuspending$default(TaskInterfaces.kt:167)
at org.utbot.rd.UtRdUtilKt$startBlocking$1.invokeSuspend(UtRdUtil.kt:30)
at kotlin.coroutines.jvm.internal.BaseContinuationImpl.resumeWith(ContinuationImpl.kt:33)
at kotlinx.coroutines.DispatchedTask.run(DispatchedTask.kt:106)
at kotlinx.coroutines.EventLoopImplBase.processNextEvent(EventLoop.common.kt:284)
at kotlinx.coroutines.BlockingCoroutine.joinBlocking(Builders.kt:85)
at kotlinx.coroutines.BuildersKt__BuildersKt.runBlocking(Builders.kt:59)
at kotlinx.coroutines.BuildersKt.runBlocking(Unknown Source)
at kotlinx.coroutines.BuildersKt__BuildersKt.runBlocking$default(Builders.kt:38)
at kotlinx.coroutines.BuildersKt.runBlocking$default(Unknown Source)
at org.utbot.rd.UtRdUtilKt.startBlocking(UtRdUtil.kt:30)
at org.utbot.intellij.plugin.process.EngineProcess.obtainClassId(EngineProcess.kt:200)
at org.utbot.intellij.plugin.generator.UtTestsDialogProcessor$createTests$1$1$run$1$2.compute(UtTestsDialogProcessor.kt:173)
at org.utbot.intellij.plugin.generator.UtTestsDialogProcessor$createTests$1$1$run$1$2.compute(UtTestsDialogProcessor.kt:171)
at com.intellij.openapi.project.DumbService.lambda$runReadActionInSmartMode$0(DumbService.java:113)
at com.intellij.openapi.project.DumbService.lambda$runReadActionInSmartMode$1(DumbService.java:157)
at com.intellij.openapi.application.impl.ApplicationImpl.runReadAction(ApplicationImpl.java:941)
at com.intellij.openapi.application.ReadAction.compute(ReadAction.java:68)
at com.intellij.openapi.project.DumbService.runReadActionInSmartMode(DumbService.java:150)
at com.intellij.openapi.project.DumbService.runReadActionInSmartMode(DumbService.java:113)
at org.utbot.intellij.plugin.generator.UtTestsDialogProcessor$createTests$1$1.run(UtTestsDialogProcessor.kt:171)
at com.intellij.openapi.progress.impl.CoreProgressManager.startTask(CoreProgressManager.java:442)
at com.intellij.openapi.progress.impl.ProgressManagerImpl.startTask(ProgressManagerImpl.java:114)
at com.intellij.openapi.progress.impl.CoreProgressManager.lambda$runProcessWithProgressAsynchronously$5(CoreProgressManager.java:493)
at com.intellij.openapi.progress.impl.ProgressRunner.lambda$submit$3(ProgressRunner.java:252)
at com.intellij.openapi.progress.impl.CoreProgressManager.lambda$runProcess$2(CoreProgressManager.java:188)
at com.intellij.openapi.progress.impl.CoreProgressManager.lambda$executeProcessUnderProgress$12(CoreProgressManager.java:608)
at com.intellij.openapi.progress.impl.CoreProgressManager.registerIndicatorAndRun(CoreProgressManager.java:683)
at com.intellij.openapi.progress.impl.CoreProgressManager.computeUnderProgress(CoreProgressManager.java:639)
at com.intellij.openapi.progress.impl.CoreProgressManager.executeProcessUnderProgress(CoreProgressManager.java:607)
at com.intellij.openapi.progress.impl.ProgressManagerImpl.executeProcessUnderProgress(ProgressManagerImpl.java:60)
at com.intellij.openapi.progress.impl.CoreProgressManager.runProcess(CoreProgressManager.java:175)
at com.intellij.openapi.progress.impl.ProgressRunner.lambda$submit$4(ProgressRunner.java:252)
at java.base/java.util.concurrent.CompletableFuture$AsyncSupply.run(CompletableFuture.java:1768)
at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136)
at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635)
at java.base/java.util.concurrent.Executors$PrivilegedThreadFactory$1$1.run(Executors.java:702)
at java.base/java.util.concurrent.Executors$PrivilegedThreadFactory$1$1.run(Executors.java:699)
at java.base/java.security.AccessController.doPrivileged(AccessController.java:399)
at java.base/java.util.concurrent.Executors$PrivilegedThreadFactory$1.run(Executors.java:699)
at java.base/java.lang.Thread.run(Thread.java:833)
2022-11-28 16:12:56,876 [1775885] SEVERE - #c.i.o.p.Task - IntelliJ IDEA 2022.2.3 Build #IU-222.4345.14
2022-11-28 16:12:56,876 [1775885] SEVERE - #c.i.o.p.Task - JDK: 17.0.4.1; VM: OpenJDK 64-Bit Server VM; Vendor: JetBrains s.r.o.
2022-11-28 16:12:56,876 [1775885] SEVERE - #c.i.o.p.Task - OS: Windows 10
2022-11-28 16:12:56,877 [1775886] SEVERE - #c.i.o.p.Task - Plugin to blame: UnitTestBot version: 2022.11.563.

28-11-2022_16-10-10.log
Details 16:10:11.627 | INFO | EngineProcessMain | RdCWARNING: Illegal reflective access by com.esotericsoftware.kryo.kryo5.unsafe.UnsafeUtil (file:/C:/Users/lWX1182794/AppData/Roaming/JetBrains/IntelliJIdea2022.2/plugins/utbot-intellij/lib/kryo5-5.3.0.jar) to constructor java.nio.DirectByteBuffer(long,int) WARNING: Illegal reflective access by com.esotericsoftware.kryo.kryo5.unsafe.UnsafeUtil (file:/C:/Users/lWX1182794/AppData/Roaming/JetBrains/IntelliJIdea2022.2/plugins/utbot-intellij/lib/kryo5-5.3.0.jar) to method sun.nio.ch.DirectBuffer.cleaner() ClientSocket : connected 16:10:11.697 | DEBUG | EngineProcessMain | RESUME :: {id = ClientSocket/Sender, state = 'AsyncProcessing'} 16:10:11.795 | INFO | EngineProcessMain | signalled 16:10:12.010 | INFO | AnalyticsConfigureUtil | PathSelectorType: INHERITORS_SELECTOR 16:12:17.802 | INFO | EngineProcessMain | terminating lifetime by timeout 16:12:17.807 | INFO | EngineProcessMain | runBlocking ending 16:12:17.807 | INFO | EngineProcessMain | ClientSocket: start terminating lifetime 16:12:17.807 | DEBUG | EngineProcessMain | ClientSocket: shutting down ack sending executor 16:12:17.807 | INFO | EngineProcessMain | runBlocking ended 16:12:17.808 | DEBUG | EngineProcessMain | ClientSocket: send buffer stopped, success: true 16:12:17.808 | DEBUG | EngineProcessMain | ClientSocket: closing socket 16:12:17.809 | DEBUG | EngineProcessMain | ClientSocket: waiting for receiver thread 16:12:17.809 | DEBUG | EngineProcessMain | Exception in SocketWire.Receive: ClientSocket: java.net.SocketException: Socket closed 16:12:17.811 | DEBUG | EngineProcessMain | ClientSocket: receiverProc finished 16:12:17.811 | DEBUG | EngineProcessMain | ClientSocket: terminated. 16:12:17.811 | INFO | EngineProcessMain | ClientSocket: termination finished

Environment

Windows 10 Pro
IntelliJ IDEA 2022.2.2
Gradle
JDK 11

Additional context

javaw.exe process was terminated (checked in Task Manager)

Activity

  1. alisevych
    added
    ctg-bugIssue is a bug
    on Nov 28, 2022
  2. alisevych
    assigned
    Domonion
    on Nov 28, 2022
  3. korifey
    added this to UTBot Javaon Nov 28, 2022
  4. korifey
    moved this to Todo in UTBot Javaon Nov 28, 2022
  5. alisevych
    changed the title [-]`Server.EngineProcessModel.obtainClassId::<<unbound>> is not bound to a protocol` exception when importing libraries in IDEA[/-] [+]`ProtocolNotBoundException` exception when importing libraries in IDEA[/+] on Nov 28, 2022

  6. Domonion commented on Nov 28, 2022

    @Domonion
    Domonion
    on Nov 28, 2022
    Collaborator

    The problem is with DumbService.runReadActionInSmartMode:
    It postpones read action until indexing finished which might take more than 2 minutes. Process would not receive any signal from parent and will consider itself as orphan thus terminate. We should somehow signal process that it should wait for any signal despite timeout

  7. alisevych
    added this to the 2022.12 Release milestone on Nov 29, 2022
  8. alisevych
    added
    comp-rdIssue is related RD
    on Dec 1, 2022
  9. Domonion
    added 3 commits that reference this issue on Dec 16, 2022

    [utbot-rd]

    fd84cd8

    [utbot-rd]

    7497cb8

    [utbot-rd]

    11ed772
  10. Domonion
    closed this as completedin #1536on Dec 16, 2022
  11. Domonion
    added a commit that references this issue on Dec 16, 2022

    Fix process dying in dumb mode (#1536)

    2f54e9f
  12. Repository owner moved this from Todo to Done in UTBot Javaon Dec 16, 2022
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Metadata

Metadata

Assignees

Labels

comp-rdIssue is related RDctg-bugIssue is a bug

Type

No type

Projects

Milestone

Relationships

None yet

Development

No branches or pull requests

Issue actions