False positive test on timeout is generated by Symbolic engine

[alisevych]

Description

False positive test on timeout is generated by Symbolic engine on sm***t project: DCMI class, qcbu method

To Reproduce

1. Install UnitTestBot plugin built from main in IntelliJ IDEA Ultimate 2023.2
2. Open sm***t project
3. Open DCMI class
4. Generate tests with Spring configuration Sm***tApplication, UnitTests, other settings as default
5. Find tests on timeout and run them

Expected behavior

No tests on timeout should be generated for the class.

Actual behavior

There are tests on timeout being generated.
They fail with NPE.
There are java.lang.InterruptedException and java.lang.ThreadDeath in utbot-engine-current.log (see below)

Screenshots, logs

    @Test
    @Timeout(value = 1000L, unit = TimeUnit.MILLISECONDS)
    public void test***_DCM***() throws ClassNotFoundException, IllegalAccessException, NoSuchFieldException, InvocationTargetException, NoSuchMethodException {
        (when(dtcmMock.get***(any()))).thenReturn(((List) null));
        setField(dscmi, "***", "dscm", dscmMock);
        
        /* This execution may take longer than the 1000 ms timeout
         and therefore fail due to exceeding the timeout. */
        assertTimeoutPreemptively(Duration.ofMillis(1000L), () -> dscmi.get***(null));
    }

13:52:14.763 | ERROR | InstrumentedProcess       | RdCategory: DynamicClassTransformer   | Error while transforming: java.lang.InterruptedException
	at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireInterruptibly(AbstractQueuedSynchronizer.java:1223)
	at java.util.concurrent.locks.ReentrantLock.lockInterruptibly(ReentrantLock.java:340)
	at org.utbot.common.StopWatch.stop(StopWatch.kt:66)
	at org.utbot.instrumentation.agent.DynamicClassTransformer.transform(DynamicClassTransformer.kt:38)
	at sun.instrument.TransformerManager.transform(TransformerManager.java:188)
	at sun.instrument.InstrumentationImpl.transform(InstrumentationImpl.java:428)
	at java.lang.ClassLoader.defineClass1(Native Method)
	at java.lang.ClassLoader.defineClass(ClassLoader.java:757)
	at java.security.SecureClassLoader.defineClass(SecureClassLoader.java:142)
	at java.net.URLClassLoader.defineClass(URLClassLoader.java:473)
	at java.net.URLClassLoader.access$100(URLClassLoader.java:74)
	at java.net.URLClassLoader$1.run(URLClassLoader.java:369)
	at java.net.URLClassLoader$1.run(URLClassLoader.java:363)
	at java.security.AccessController.doPrivileged(Native Method)
	at java.net.URLClassLoader.findClass(URLClassLoader.java:362)
	at java.lang.ClassLoader.loadClass(ClassLoader.java:419)
	at org.utbot.instrumentation.process.HandlerClassesLoader.loadClass(InstrumentedProcessMain.kt:54)
	at java.lang.ClassLoader.loadClass(ClassLoader.java:352)
	at ch.qos.logback.classic.PatternLayout.<clinit>(PatternLayout.java:111)
	at ch.qos.logback.classic.encoder.PatternLayoutEncoder.start(PatternLayoutEncoder.java:24)
	at ch.qos.logback.core.joran.action.NestedComplexPropertyIA.end(NestedComplexPropertyIA.java:161)
	at ch.qos.logback.core.joran.spi.Interpreter.callEndAction(Interpreter.java:309)
	at ch.qos.logback.core.joran.spi.Interpreter.endElement(Interpreter.java:193)
	at ch.qos.logback.core.joran.spi.Interpreter.endElement(Interpreter.java:179)
	at ch.qos.logback.core.joran.spi.EventPlayer.play(EventPlayer.java:62)
	at ch.qos.logback.core.joran.GenericConfigurator.doConfigure(GenericConfigurator.java:165)
	at ch.qos.logback.core.joran.GenericConfigurator.doConfigure(GenericConfigurator.java:152)
	at ch.qos.logback.core.joran.GenericConfigurator.doConfigure(GenericConfigurator.java:110)
	at ch.qos.logback.core.joran.GenericConfigurator.doConfigure(GenericConfigurator.java:53)
	at ch.qos.logback.classic.util.ContextInitializer.configureByResource(ContextInitializer.java:64)
	at ch.qos.logback.classic.util.ContextInitializer.autoConfig(ContextInitializer.java:134)
	at org.slf4j.impl.StaticLoggerBinder.init(StaticLoggerBinder.java:84)
	at org.slf4j.impl.StaticLoggerBinder.<clinit>(StaticLoggerBinder.java:55)
	at org.slf4j.LoggerFactory.bind(LoggerFactory.java:150)
	at org.slf4j.LoggerFactory.performInitialization(LoggerFactory.java:124)
	at org.slf4j.LoggerFactory.getILoggerFactory(LoggerFactory.java:417)
	at org.slf4j.LoggerFactory.getLogger(LoggerFactory.java:362)
	at org.slf4j.LoggerFactory.getLogger(LoggerFactory.java:388)
	at com.***
	at sun.misc.Unsafe.allocateInstance(Native Method)
	at org.utbot.framework.plugin.api.util.ReflectionUtilsKt.getAnyInstance(ReflectionUtils.kt:45)
	at org.utbot.instrumentation.instrumentation.execution.constructors.InstrumentationContextAwareValueConstructor.constructObject(InstrumentationContextAwareValueConstructor.kt:142)
	at org.utbot.instrumentation.instrumentation.execution.constructors.InstrumentationContextAwareValueConstructor.construct(InstrumentationContextAwareValueConstructor.kt:107)
	at org.utbot.instrumentation.instrumentation.execution.constructors.InstrumentationContextAwareValueConstructor.constructMethodParameters(InstrumentationContextAwareValueConstructor.kt:88)
	at org.utbot.instrumentation.instrumentation.execution.phases.ValueConstructionPhase.constructParameters(ValueConstructionPhase.kt:47)
	at org.utbot.instrumentation.instrumentation.execution.phases.PhasesController$applyPreprocessing$constructedData$1.invoke(PhasesController.kt:96)
	at org.utbot.instrumentation.instrumentation.execution.phases.PhasesController$applyPreprocessing$constructedData$1.invoke(PhasesController.kt:95)
	at org.utbot.instrumentation.instrumentation.execution.phases.PhasesController$executePhaseInTimeout$1$result$1.invoke(PhasesController.kt:73)
	at org.utbot.common.ThreadBasedExecutor$invokeWithTimeout$1.invoke(ThreadUtil.kt:49)
	at org.utbot.common.ThreadBasedExecutor$ensureThreadIsAlive$1.invoke(ThreadUtil.kt:97)
	at org.utbot.common.ThreadBasedExecutor$ensureThreadIsAlive$1.invoke(ThreadUtil.kt:93)
	at kotlin.concurrent.ThreadsKt$thread$thread$1.run(Thread.kt:30)
 
13:52:14.766 | INFO  | InstrumentedProcess       | RdCategory: DynamicClassTransformer   | Transformed: ch/qos/logback/classic/pattern/ContextNameConverter 
13:52:14.776 | ERROR | InstrumentedProcess       | RdCategory: DynamicClassTransformer   | Error while transforming: java.lang.ThreadDeath
	at java.lang.Thread.stop(Thread.java:858)
	at org.utbot.common.ThreadBasedExecutor.invokeWithTimeout-RgG5Fkc(ThreadUtil.kt:72)
	at org.utbot.instrumentation.instrumentation.execution.phases.PhasesController$executePhaseInTimeout$1.invoke(PhasesController.kt:70)
	at org.utbot.instrumentation.instrumentation.execution.phases.PhasesController$executePhaseInTimeout$1.invoke(PhasesController.kt:65)
	at org.utbot.instrumentation.instrumentation.execution.phases.ExecutionPhaseKt.start(ExecutionPhase.kt:25)
	at org.utbot.instrumentation.instrumentation.execution.phases.PhasesController.executePhaseInTimeout(PhasesController.kt:65)
	at org.utbot.instrumentation.instrumentation.execution.phases.PhasesController.applyPreprocessing(PhasesController.kt:95)
	at org.utbot.instrumentation.instrumentation.execution.SimpleUtExecutionInstrumentation$invoke$1$1.invoke(SimpleUtExecutionInstrumentation.kt:65)
	at org.utbot.instrumentation.instrumentation.execution.SimpleUtExecutionInstrumentation$invoke$1$1.invoke(SimpleUtExecutionInstrumentation.kt:62)
	at org.utbot.instrumentation.instrumentation.execution.UtExecutionInstrumentation$invoke$1.invoke(UtExecutionInstrumentation.kt:46)
	at org.utbot.instrumentation.instrumentation.execution.UtExecutionInstrumentation$invoke$1.invoke(UtExecutionInstrumentation.kt:45)
	at org.utbot.instrumentation.instrumentation.execution.SimpleUtExecutionInstrumentation.invoke(SimpleUtExecutionInstrumentation.kt:62)
	at org.utbot.instrumentation.instrumentation.execution.UtExecutionInstrumentation$DefaultImpls.invoke(UtExecutionInstrumentation.kt:45)
	at org.utbot.instrumentation.instrumentation.execution.SimpleUtExecutionInstrumentation.invoke(SimpleUtExecutionInstrumentation.kt:26)
	at org.utbot.instrumentation.instrumentation.execution.SimpleUtExecutionInstrumentation.invoke(SimpleUtExecutionInstrumentation.kt:26)
	at org.utbot.instrumentation.process.InstrumentedProcessMainKt$setup$2.invoke(InstrumentedProcessMain.kt:130)
	at org.utbot.instrumentation.process.InstrumentedProcessMainKt$setup$2.invoke(InstrumentedProcessMain.kt:127)
	at org.utbot.rd.IdleWatchdog$measureTimeForActiveCall$1$2$1.invoke(ClientProcessUtil.kt:115)
	at org.utbot.rd.IdleWatchdog.wrapActive(ClientProcessUtil.kt:88)
	at org.utbot.rd.IdleWatchdog$measureTimeForActiveCall$1.invoke(ClientProcessUtil.kt:114)
	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:362)
	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.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
	at java.lang.Thread.run(Thread.java:750)
 
...

13:52:15.846 | ERROR | InstrumentedProcess       | RdCategory: DynamicClassTransformer   | Error while transforming: java.lang.InterruptedException
	at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireInterruptibly(AbstractQueuedSynchronizer.java:1223)
	at java.util.concurrent.locks.ReentrantLock.lockInterruptibly(ReentrantLock.java:340)
	at org.utbot.common.StopWatch.stop(StopWatch.kt:66)
	at org.utbot.instrumentation.agent.DynamicClassTransformer.transform(DynamicClassTransformer.kt:38)
	at sun.instrument.TransformerManager.transform(TransformerManager.java:188)
	at sun.instrument.InstrumentationImpl.transform(InstrumentationImpl.java:428)
	at java.lang.ClassLoader.defineClass1(Native Method)
	at java.lang.ClassLoader.defineClass(ClassLoader.java:757)
	at java.security.SecureClassLoader.defineClass(SecureClassLoader.java:142)
	at java.net.URLClassLoader.defineClass(URLClassLoader.java:473)
	at java.net.URLClassLoader.access$100(URLClassLoader.java:74)
	at java.net.URLClassLoader$1.run(URLClassLoader.java:369)
	at java.net.URLClassLoader$1.run(URLClassLoader.java:363)
	at java.security.AccessController.doPrivileged(Native Method)
	at java.net.URLClassLoader.findClass(URLClassLoader.java:362)
	at java.lang.ClassLoader.loadClass(ClassLoader.java:419)
	at sun.misc.Launcher$AppClassLoader.loadClass(Launcher.java:352)
	at java.lang.ClassLoader.loadClass(ClassLoader.java:352)
	at org.utbot.instrumentation.instrumentation.execution.phases.PhasesController$executePhaseInTimeout$1$result$1.invoke(PhasesController.kt:125)
	at org.utbot.common.ThreadBasedExecutor$invokeWithTimeout$1.invoke(ThreadUtil.kt:49)
	at org.utbot.common.ThreadBasedExecutor$ensureThreadIsAlive$1.invoke(ThreadUtil.kt:97)
	at org.utbot.common.ThreadBasedExecutor$ensureThreadIsAlive$1.invoke(ThreadUtil.kt:93)
	at kotlin.concurrent.ThreadsKt$thread$thread$1.run(Thread.kt:30)

Environment

IntelliJ IDEA version - Ultimate 2023.2
Project - sm***t, Maven
JDK - 1.8

Additional context

Reproducing for customer.
Probably related issue:

• Timeout tests are sometimes generated by Fuzzing for simple functions #2262

[alisevych]

Closing as not reproducing any more with plugin built from the latest main.