Skip to content

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

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Open
tyuldashev opened this issue Jul 13, 2023 · 1 comment
Assignees
Labels
comp-codegen Issue is related to code generator ctg-bug Issue is a bug spec-performance Performance-related issue

Comments

@tyuldashev
Copy link
Collaborator

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.

@tyuldashev tyuldashev added ctg-bug Issue is a bug comp-codegen Issue is related to code generator labels Jul 13, 2023
@alisevych alisevych added spec-performance Performance-related issue comp-symbolic-engine Issue is related to the symbolic execution engine comp-fuzzing Issue is related to the fuzzing and removed comp-codegen Issue is related to code generator comp-symbolic-engine Issue is related to the symbolic execution engine comp-fuzzing Issue is related to the fuzzing labels Jul 13, 2023
@tyuldashev tyuldashev added the comp-codegen Issue is related to code generator label Jul 13, 2023
@tyuldashev tyuldashev changed the title UTBot cannot generate test for simple function when user set small timeout UTBot cannot generate test for simple function when user sets small timeout Jul 13, 2023
@tyuldashev tyuldashev added this to the September Release milestone Sep 11, 2023
@alisevych
Copy link
Member

@tyuldashev
The issue is Not reproducing for me on the latest main.
I've tried Symbolic 100% mode with timeout 4/5 sec - and tests are generated successfully.
With 4 sec - one successful only, with 5 sec - both positive and on division by zero.

It can be related to performance of your PC, allocating memory lack, probably? Can you check how much space you have on C and also try to close as much applications as possible?
BTW I have 2 IDEAs opened with 3 projects - when I tried to reproduce it.

@alisevych alisevych removed this from the October Release milestone Sep 26, 2023
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
comp-codegen Issue is related to code generator ctg-bug Issue is a bug spec-performance Performance-related issue
Projects
Status: Todo
Development

No branches or pull requests

3 participants