Skip to content

UTBot cannot generate test for simple function when user sets small timeout #2410

Open
@tyuldashev

Description

@tyuldashev

Description
When user reduce Test generation timeout to about 10 seconds or smaller UTBot most of the time cannot generate any of the test even for one simple function no matter if Fuzzer or Symbolic engine is used.

To Reproduce

  1. Install UnitTestBot plugin built from main in IntelliJ IDEA
  2. Invoke test generation for some simple function like division of two integers
  3. Set Test generation timeout to 5 seconds
  4. Start test generation

Expected behavior
Tests are generated, at least a positive one.

Actual behavior
Error message appears that no tests are generated.

Screenshots, logs

utbot log
---------------------------------------------------------------------------------------- 
11:46:11.760 | INFO  | EngineProcessMain         | -----------------------------------------------------------------------
11:46:11.762 | INFO  | EngineProcessMain         | -------------------NEW ENGINE PROCESS STARTED--------------------------
11:46:11.762 | INFO  | EngineProcessMain         | -----------------------------------------------------------------------
11:46:12.176 | INFO  | AnalyticsConfigureUtil    | PathSelectorType: INHERITORS_SELECTOR
11:46:19.267 | INFO  | TestCaseGenerator         | Resuming method Main.div
11:46:20.080 | INFO  | JavaLanguage              | Starting fuzzing for method: Main.div
11:46:20.082 | INFO  | JavaLanguage              | 	use thisInstance = true
11:46:20.084 | INFO  | JavaLanguage              | 	parameters = [int, int]
11:46:20.253 | INFO  | InstrumentedProcess       | ------------------------------------------------------------------
--------Instrumented process started with PID=26720--------
------------------------------------------------------------------
11:46:21.618 | INFO  | TestCaseGenerator         | Resuming method Main.div
11:46:23.968 | INFO  | TestCaseGenerator         | Resuming method Main.div
11:46:24.288 | INFO  | ConcreteExecutor          | RdCategory: Server                    | ServerSocket: start terminating lifetime 
11:46:24.292 | INFO  | ConcreteExecutor          | RdCategory: Server                    | ServerSocket: termination finished 
11:46:24.301 | ERROR | ConcreteExecutor          | executeAsync, response(ERROR)
org.utbot.framework.plugin.api.InstrumentedProcessDeathException: 
----------------------------------------
The instrumented process is dead
Cause:
Timeout
----------------------------------------

	at org.utbot.instrumentation.ConcreteExecutor.withProcess$throwConcreteIfDead(ConcreteExecutor.kt:181) ~[utbot-instrumentation-2023.7.4837.jar:?]
	at org.utbot.instrumentation.ConcreteExecutor.withProcess(ConcreteExecutor.kt:204) ~[utbot-instrumentation-2023.7.4837.jar:?]
	at org.utbot.instrumentation.ConcreteExecutor$withProcess$1.invokeSuspend(ConcreteExecutor.kt) ~[utbot-instrumentation-2023.7.4837.jar:?]
	at kotlin.coroutines.jvm.internal.BaseContinuationImpl.resumeWith(ContinuationImpl.kt:33) ~[kotlin-stdlib-1.8.10.jar:1.8.10-release-430(1.8.10)]
	at kotlinx.coroutines.DispatchedTask.run(DispatchedTask.kt:104) ~[kotlinx-coroutines-core-jvm-1.6.3.jar:?]
	at kotlinx.coroutines.EventLoopImplBase.processNextEvent(EventLoop.common.kt:284) ~[kotlinx-coroutines-core-jvm-1.6.3.jar:?]
	at kotlinx.coroutines.BlockingCoroutine.joinBlocking(Builders.kt:85) ~[kotlinx-coroutines-core-jvm-1.6.3.jar:?]
	at kotlinx.coroutines.BuildersKt__BuildersKt.runBlocking(Builders.kt:59) ~[kotlinx-coroutines-core-jvm-1.6.3.jar:?]
	at kotlinx.coroutines.BuildersKt.runBlocking(Unknown Source) ~[kotlinx-coroutines-core-jvm-1.6.3.jar:?]
	at kotlinx.coroutines.BuildersKt__BuildersKt.runBlocking$default(Builders.kt:38) ~[kotlinx-coroutines-core-jvm-1.6.3.jar:?]
	at kotlinx.coroutines.BuildersKt.runBlocking$default(Unknown Source) ~[kotlinx-coroutines-core-jvm-1.6.3.jar:?]
	at org.utbot.common.ConcurrencyKt.runBlockingWithCancellationPredicate(Concurrency.kt:38) ~[utbot-core-2023.7.4837.jar:?]
	at org.utbot.framework.plugin.api.TestCaseGenerator$generate$2$3.invoke(TestCaseGenerator.kt:207) ~[utbot-framework-2023.7.4837.jar:?]
	at org.utbot.framework.plugin.api.TestCaseGenerator$generate$2$3.invoke(TestCaseGenerator.kt:206) ~[utbot-framework-2023.7.4837.jar:?]
	at org.utbot.common.ConcurrencyKt.runIgnoringCancellationException(Concurrency.kt:47) ~[utbot-core-2023.7.4837.jar:?]
	at org.utbot.framework.plugin.api.TestCaseGenerator.generate(TestCaseGenerator.kt:206) ~[utbot-framework-2023.7.4837.jar:?]
	at org.utbot.framework.process.EngineProcessMainKt$setup$4.invoke(EngineProcessMain.kt:135) ~[utbot-framework-2023.7.4837.jar:?]
	at org.utbot.framework.process.EngineProcessMainKt$setup$4.invoke(EngineProcessMain.kt:120) ~[utbot-framework-2023.7.4837.jar:?]
	at org.utbot.rd.IdleWatchdog$measureTimeForActiveCall$1$2$1.invoke(ClientProcessUtil.kt:115) ~[utbot-rd-2023.7.4837.jar:?]
	at org.utbot.rd.IdleWatchdog.wrapActive(ClientProcessUtil.kt:88) ~[utbot-rd-2023.7.4837.jar:?]
	at org.utbot.rd.IdleWatchdog$measureTimeForActiveCall$1.invoke(ClientProcessUtil.kt:114) ~[utbot-rd-2023.7.4837.jar:?]
	at com.jetbrains.rd.framework.IRdEndpoint$set$1.invoke(TaskInterfaces.kt:182) ~[rd-framework-2023.1.2.jar:?]
	at com.jetbrains.rd.framework.IRdEndpoint$set$1.invoke(TaskInterfaces.kt:182) ~[rd-framework-2023.1.2.jar:?]
	at com.jetbrains.rd.framework.impl.RdCall.onWireReceived(RdTask.kt:362) ~[rd-framework-2023.1.2.jar:?]
	at com.jetbrains.rd.framework.MessageBroker$invoke$2$2.invoke(MessageBroker.kt:57) ~[rd-framework-2023.1.2.jar:?]
	at com.jetbrains.rd.framework.MessageBroker$invoke$2$2.invoke(MessageBroker.kt:56) ~[rd-framework-2023.1.2.jar:?]
	at com.jetbrains.rd.framework.impl.ProtocolContexts.readMessageContextAndInvoke(ProtocolContexts.kt:148) ~[rd-framework-2023.1.2.jar:?]
	at com.jetbrains.rd.framework.MessageBroker$invoke$2.invoke(MessageBroker.kt:56) ~[rd-framework-2023.1.2.jar:?]
	at com.jetbrains.rd.framework.MessageBroker$invoke$2.invoke(MessageBroker.kt:54) ~[rd-framework-2023.1.2.jar:?]
	at com.jetbrains.rd.util.threading.SingleThreadSchedulerBase.queue$lambda-3(SingleThreadScheduler.kt:41) ~[rd-core-2023.1.2.jar:?]
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) [?:?]
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) [?:?]
	at java.lang.Thread.run(Thread.java:829) [?:?]
Caused by: java.util.concurrent.CancellationException: Timeout
	at kotlinx.coroutines.ExceptionsKt.CancellationException(Exceptions.kt:22) ~[kotlinx-coroutines-core-jvm-1.6.3.jar:?]
	at kotlinx.coroutines.JobKt__JobKt.cancel(Job.kt:596) ~[kotlinx-coroutines-core-jvm-1.6.3.jar:?]
	at kotlinx.coroutines.JobKt.cancel(Unknown Source) ~[kotlinx-coroutines-core-jvm-1.6.3.jar:?]
	at kotlinx.coroutines.JobKt__JobKt.cancel$default(Job.kt:596) ~[kotlinx-coroutines-core-jvm-1.6.3.jar:?]
	at kotlinx.coroutines.JobKt.cancel$default(Unknown Source) ~[kotlinx-coroutines-core-jvm-1.6.3.jar:?]
	at org.utbot.framework.plugin.api.TestCaseGenerator.updateLifecycle(TestCaseGenerator.kt:368) ~[utbot-framework-2023.7.4837.jar:?]
	at org.utbot.framework.plugin.api.TestCaseGenerator.access$updateLifecycle(TestCaseGenerator.kt:63) ~[utbot-framework-2023.7.4837.jar:?]
	at org.utbot.framework.plugin.api.TestCaseGenerator$generate$2$3$1$2.invokeSuspend(TestCaseGenerator.kt:277) ~[utbot-framework-2023.7.4837.jar:?]
	at ���(Coroutine boundary.�(�) ~[?:?]
	at com.jetbrains.rd.framework.TaskInterfacesKt.awaitInternal(TaskInterfaces.kt:187) ~[rd-framework-2023.1.2.jar:?]
	at com.jetbrains.rd.framework.impl.RdCall.startSuspendingImpl(RdTask.kt:304) ~[rd-framework-2023.1.2.jar:?]
	at com.jetbrains.rd.framework.impl.RdCall.startSuspending(RdTask.kt:259) ~[rd-framework-2023.1.2.jar:?]
	at org.utbot.instrumentation.rd.InstrumentedProcess$Companion.invoke(InstrumentedProcess.kt:132) ~[utbot-instrumentation-2023.7.4837.jar:?]
	at org.utbot.instrumentation.ConcreteExecutor.regenerate(ConcreteExecutor.kt:158) ~[utbot-instrumentation-2023.7.4837.jar:?]
	at org.utbot.instrumentation.ConcreteExecutor.withProcess(ConcreteExecutor.kt:197) ~[utbot-instrumentation-2023.7.4837.jar:?]
	at org.utbot.instrumentation.ConcreteExecutor.executeAsync(ConcreteExecutor.kt:226) ~[utbot-instrumentation-2023.7.4837.jar:?]
	at org.utbot.engine.UtBotSymbolicEngineKt.executeConcretely(UtBotSymbolicEngine.kt:750) ~[utbot-framework-2023.7.4837.jar:?]
	at org.utbot.engine.UtBotSymbolicEngine$fuzzing$2$1.invokeSuspend(UtBotSymbolicEngine.kt:472) ~[utbot-framework-2023.7.4837.jar:?]
	at org.utbot.fuzzing.JavaLanguageKt$runJavaFuzzing$5.invokeSuspend(JavaLanguage.kt:129) ~[utbot-java-fuzzing-2023.7.4837.jar:?]
	at org.utbot.fuzzing.FuzzingApi.fuzz(Api.kt:351) ~[utbot-fuzzing-2023.7.4837.jar:?]
	at org.utbot.fuzzing.JavaLanguageKt.runJavaFuzzing(JavaLanguage.kt:120) ~[utbot-java-fuzzing-2023.7.4837.jar:?]
	at org.utbot.engine.UtBotSymbolicEngine$fuzzing$2.invokeSuspend(UtBotSymbolicEngine.kt:442) ~[utbot-framework-2023.7.4837.jar:?]
	at kotlinx.coroutines.flow.AbstractFlow.collect(Flow.kt:230) ~[kotlinx-coroutines-core-jvm-1.6.3.jar:?]
	at kotlinx.coroutines.flow.FlowKt__MergeKt$flattenConcat$1$1.emit(Merge.kt:80) ~[kotlinx-coroutines-core-jvm-1.6.3.jar:?]
	at kotlinx.coroutines.flow.FlowKt__BuildersKt$flowOf$$inlined$unsafeFlow$1.collect(Builders.kt:114) ~[kotlinx-coroutines-core-jvm-1.6.3.jar:?]
	at kotlinx.coroutines.flow.FlowKt__ErrorsKt.catchImpl(Errors.kt:156) ~[kotlinx-coroutines-core-jvm-1.6.3.jar:?]
	at kotlinx.coroutines.flow.FlowKt__ErrorsKt$catch$$inlined$unsafeFlow$1.collect(Errors.kt:113) ~[kotlinx-coroutines-core-jvm-1.6.3.jar:?]
	at org.utbot.framework.plugin.api.TestCaseGenerator$generate$2$3$1$1.invokeSuspend(TestCaseGenerator.kt:233) ~[utbot-framework-2023.7.4837.jar:?]
Caused by: java.util.concurrent.CancellationException: Timeout
	at kotlinx.coroutines.ExceptionsKt.CancellationException(Exceptions.kt:22) ~[kotlinx-coroutines-core-jvm-1.6.3.jar:?]
	at kotlinx.coroutines.JobKt__JobKt.cancel(Job.kt:596) ~[kotlinx-coroutines-core-jvm-1.6.3.jar:?]
	at kotlinx.coroutines.JobKt.cancel(Unknown Source) ~[kotlinx-coroutines-core-jvm-1.6.3.jar:?]
	at kotlinx.coroutines.JobKt__JobKt.cancel$default(Job.kt:596) ~[kotlinx-coroutines-core-jvm-1.6.3.jar:?]
	at kotlinx.coroutines.JobKt.cancel$default(Unknown Source) ~[kotlinx-coroutines-core-jvm-1.6.3.jar:?]
	at org.utbot.framework.plugin.api.TestCaseGenerator.updateLifecycle(TestCaseGenerator.kt:368) ~[utbot-framework-2023.7.4837.jar:?]
	at org.utbot.framework.plugin.api.TestCaseGenerator.access$updateLifecycle(TestCaseGenerator.kt:63) ~[utbot-framework-2023.7.4837.jar:?]
	at org.utbot.framework.plugin.api.TestCaseGenerator$generate$2$3$1$2.invokeSuspend(TestCaseGenerator.kt:277) ~[utbot-framework-2023.7.4837.jar:?]
	at kotlin.coroutines.jvm.internal.BaseContinuationImpl.resumeWith(ContinuationImpl.kt:33) ~[kotlin-stdlib-1.8.10.jar:1.8.10-release-430(1.8.10)]
	at kotlinx.coroutines.DispatchedTask.run(DispatchedTask.kt:106) ~[kotlinx-coroutines-core-jvm-1.6.3.jar:?]
	at kotlinx.coroutines.scheduling.CoroutineScheduler.runSafely(CoroutineScheduler.kt:570) ~[kotlinx-coroutines-core-jvm-1.6.3.jar:?]
	at kotlinx.coroutines.scheduling.CoroutineScheduler$Worker.executeTask(CoroutineScheduler.kt:749) ~[kotlinx-coroutines-core-jvm-1.6.3.jar:?]
	at kotlinx.coroutines.scheduling.CoroutineScheduler$Worker.runWorker(CoroutineScheduler.kt:677) ~[kotlinx-coroutines-core-jvm-1.6.3.jar:?]
	at kotlinx.coroutines.scheduling.CoroutineScheduler$Worker.run(CoroutineScheduler.kt:664) ~[kotlinx-coroutines-core-jvm-1.6.3.jar:?]
11:46:24.338 | INFO  | JavaLanguage              | Fuzzing is stopped because of timeout. Total execution time: 4258 ms
11:46:24.448 | INFO  | Summarization             | Started: ----------------------------------------------------------------------------------------
-------------------Summarization started for 1 test cases--------------------
----------------------------------------------------------------------------------------
11:46:24.448 | INFO  | Summarization             | Started: Summarization for Main.div
11:46:24.456 | INFO  | Summarization             | Diversity execution path percentage: 100
11:46:24.469 | INFO  | Summarization             | No execution traces found in test case for method Main,     public int div(int, int)
    {
        int i0, i1, i2;
        Main r0;

        r0 := @this: Main;

        i0 := @parameter0: int;

        i1 := @parameter1: int;

        i2 = i0 / i1;

        return i2;
    }

11:46:24.471 | INFO  | Summarization             | Finished (in 0,022 sec): Summarization for Main.div <Nothing>
11:46:24.472 | INFO  | Summarization             | Finished (in 0,024 sec): ----------------------------------------------------------------------------------------
-------------------Summarization started for 1 test cases--------------------
---------------------------------------------------------------------------------------- 

Additional context
Even increasing timeout to 10second doesn't guarantee that test are generated for such simple function. For more complex cases UTBot timeout less than 10 becomes useless.

If that's not a problem we could solve, then probably we need to limit bottom boundary of timeout.

Metadata

Metadata

Assignees

Labels

comp-codegenIssue is related to code generatorctg-bugIssue is a bugspec-performancePerformance-related issue

Type

No type

Projects

Status

Todo

Milestone

No milestone

Relationships

None yet

Development

No branches or pull requests

Issue actions