Exception in concrete execution of Recursion and empty test class generated

[alisevych]

Description

Empty test class is generated for Recursion and java.lang.Exception from com.jetbrains.rd.util.SwitchLogger.log (many recursive calls of Recursion.fib inside).

To Reproduce

1. Run the 'UTBotJava' project in IntelliJ Idea
2. Install RC plugin build
3. Find utbot-sample/src/main/java/org/utbot/examples/recursion/Recursion.java
4. Fuzzing - Symbolic has default settings, enable concrete executor logs
5. Use plugin to generate tests for Recursion.fib()
6. Wait for generation to finish

Expected behavior

Tests are supposed to be generated.

Actual behavior

Empty test class was generated. That happened also when testing previous release.
The following exception is in concrete executor logs (last line repeats 1014 times).

Visual proofs (screenshots, logs, images)

InterruptedException was thrown once:

19:30:01.014 | Error | SingleThreadScheduler     | 16:Scheduler for Client57181 @coroutine#158 |  | java.lang.InterruptedException
	at java.base/java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2109)
	at java.base/java.util.concurrent.ThreadPoolExecutor.awaitTermination(ThreadPoolExecutor.java:1454)
	at com.jetbrains.rd.util.threading.SingleThreadScheduler$1.invoke(SingleThreadScheduler.kt:70)
	at com.jetbrains.rd.util.threading.SingleThreadScheduler$1.invoke(SingleThreadScheduler.kt:66)
	at com.jetbrains.rd.util.lifetime.LifetimeDefinition.destruct(RLifetime.kt:427)
	at com.jetbrains.rd.util.lifetime.LifetimeDefinition.terminate(RLifetime.kt:408)
	at com.jetbrains.rd.util.lifetime.LifetimeDefinition.terminate$default(RLifetime.kt:375)
	at org.utbot.rd.CallsSynchronizer.stopProtocol(ClientProcessUtil.kt:108)
	at org.utbot.instrumentation.process.ChildProcessKt$setup$5.invoke(ChildProcess.kt:153)
	at org.utbot.instrumentation.process.ChildProcessKt$setup$5.invoke(ChildProcess.kt:151)
	at org.utbot.rd.CallsSynchronizer$measureExecutionForTermination$2$1$1.invoke(ClientProcessUtil.kt:79)
	at org.utbot.rd.CallsSynchronizer$measureExecutionForTermination$1.invokeSuspend(ClientProcessUtil.kt:69)
	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.CallsSynchronizer.measureExecutionForTermination(ClientProcessUtil.kt:66)
	at org.utbot.rd.CallsSynchronizer$measureExecutionForTermination$2$1.invokeSuspend(ClientProcessUtil.kt:78)
	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.CallsSynchronizer$measureExecutionForTermination$2.invoke(ClientProcessUtil.kt:77)
	at com.jetbrains.rd.framework.IRdEndpoint$set$1.invoke(TaskInterfaces.kt:182)
	at com.jetbrains.rd.framework.IRdEndpoint$set$1.invoke(TaskInterfaces.kt:182)
	at com.jetbrains.rd.framework.impl.RdCall.onWireReceived(RdTask.kt:360)
	at com.jetbrains.rd.framework.MessageBroker$invoke$2$2.invoke(MessageBroker.kt:57)
	at com.jetbrains.rd.framework.MessageBroker$invoke$2$2.invoke(MessageBroker.kt:56)
	at com.jetbrains.rd.framework.impl.ProtocolContexts.readMessageContextAndInvoke(ProtocolContexts.kt:148)
	at com.jetbrains.rd.framework.MessageBroker$invoke$2.invoke(MessageBroker.kt:56)
	at com.jetbrains.rd.framework.MessageBroker$invoke$2.invoke(MessageBroker.kt:54)
	at com.jetbrains.rd.util.threading.SingleThreadSchedulerBase.queue$lambda-3(SingleThreadScheduler.kt:41)
	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:829)

Exception from logger with 1014 calls of Recursion.fib is reproducing constantly:

19:29:03.662 | Info  | DynamicClassTransformer   | 16:Scheduler for Client57181 @coroutine#10 | Transforming: org/utbot/examples/recursion/Recursion 
19:29:04.505 | Error | RuntimeTraceStorage       | 22:executor     | Stack overflow (increase stack size Settings.TRACE_ARRAY_SIZE) | java.lang.Exception
	at com.jetbrains.rd.util.LoggerKt.defaultLogFormat(Logger.kt:80)
	at org.utbot.rd.loggers.UtRdConsoleLogger.log(UtRdConsoleLogger.kt:24)
	at com.jetbrains.rd.util.SwitchLogger.log(Logger.kt:47)
	at org.utbot.instrumentation.instrumentation.et.RuntimeTraceStorage.visit(TraceHandler.kt:162)
	at org.utbot.examples.recursion.Recursion.fib(Recursion.java:21)
	at org.utbot.examples.recursion.Recursion.fib(Recursion.java:22)
	at org.utbot.examples.recursion.Recursion.fib(Recursion.java:22)
	at org.utbot.examples.recursion.Recursion.fib(Recursion.java:22)
	at org.utbot.examples.recursion.Recursion.fib(Recursion.java:22)
	at org.utbot.examples.recursion.Recursion.fib(Recursion.java:22)
	at org.utbot.examples.recursion.Recursion.fib(Recursion.java:22)
	at org.utbot.examples.recursion.Recursion.fib(Recursion.java:22)
	at org.utbot.examples.recursion.Recursion.fib(Recursion.java:22)
        ...
        at org.utbot.instrumentation.instrumentation.InvokeInstrumentation$invoke$2$result$1.invoke-IoAF18A(InvokeInstrumentation.kt:60)

full concrete execution.log

Environment

Windows 10 Pro
IntelliJ IDEA 2022.2.2 (Ultimate)

Additional context

Originally posted by @alisevych in #1125 (comment)

[alisevych]

@Domonion @sergeypospelov
Today reproducing only exception from logger.
Test generation is not blocked, RecursionTest class is created.
Yesterday there was InterruptedException also in logs and an empty class was generated.
Please check. That also happened when testing previous release.

[denis-fokin]

Not a recent regression. Postpone to the next release.

[Domonion]

Tests are generated with latest main. @alisevych

[alisevych]

Closing as not reproducible. Tests are generated, no exception is thrown.