Redesign for Concrete Executor timeout (#1728)

* Create ResultAndErrorHandlingApiOfTheInstrumentedProcess.md

* [utbot-java]
1. New timeouts system for contest estimator.
2. Concrete execution phases redesign
Fix #1726
Possible fix #1718

* [utbot-java]
If docker image for monitoring is not available - CI should continue
even without monitoring

* [utbot-java]
Mockito warmup as it takes too much time in tests to initialize it

* [utbot-java]
Providing additional auxiliary log information when running in docker

* Fix: document

* [utbot-java]
Review fix

Co-authored-by: Sergey Pospelov <sergeypospelov59@gmail.com>

Author: Domonion

.github/workflows/build-and-run-tests-from-branch.yml

@@ -99,6 +99,7 @@ jobs:
       - name: Run monitoring
         # secret uploaded using base64 encoding to have one-line output:
         # cat file | base64 -w 0
+        continue-on-error: true
         run: |
           chmod +x ./scripts/project/monitoring.sh
           ./scripts/project/monitoring.sh "${PUSHGATEWAY_HOSTNAME}" "${{ secrets.PUSHGATEWAY_USER }}" "${{ secrets.PUSHGATEWAY_PASSWORD }}"

build.gradle.kts

@@ -53,6 +53,10 @@ allprojects {
             }
         }
         withType<Test> {
+            // uncomment if you want to see loggers output in console
+            // this is useful if you debug in docker
+            // testLogging.showStandardStreams = true
+            // testLogging.showStackTraces = true
             // set heap size for the test JVM(s)
             minHeapSize = "128m"
             maxHeapSize = "3072m"
@@ -68,6 +72,9 @@ allprojects {
                 override fun beforeTest(testDescriptor: TestDescriptor) {}
                 override fun afterTest(testDescriptor: TestDescriptor, result: TestResult) {
                     println("[$testDescriptor.classDisplayName] [$testDescriptor.displayName]: $result.resultType, length - ${(result.endTime - result.startTime) / 1000.0} sec")
+                    if (result.resultType == TestResult.ResultType.FAILURE) {
+                        println("Exception: " + result.exception?.stackTraceToString())
+                    }
                 }
 
                 override fun afterSuite(testDescriptor: TestDescriptor, result: TestResult) {

docs/ResultAndErrorHandlingApiOfTheInstrumentedProcess.md

@@ -0,0 +1,55 @@
+# Result & Error Handling API of the Instrumented Process
+
+## Terminology
+
+- The _instrumented process_ is an external process used for the isolated invocation.
+- The `ConcreteExecutor` is a class which provides smooth and concise interaction with the _instrumented process_. It works in the _main process_.
+- A client is an object which directly uses the `ConcreteExecutor`, so it works in the _main process_ as well.
+- An _Instrumentation_ is an object which has to be passed to the `ConcreteExecutor`. It defines the logic of invocation and bytecode instrumentation in the _instrumented process_.
+
+## Common
+
+Basically, if any exception happens inside the _instrumented process_, it is rethrown to the client process via RD.
+- Errors which do not cause the termination of the _instrumented process_ are wrapped in `InstrumentedProcessError`. Process won't be restarted, so client's requests will be handled by the same process. We believe, that the state of the _instrumented process_ is consistent, but in some tricky situations it **may be not**. Such situations should be reported as bugs.
+- Some of the errors lead to the instant death of the _instrumented process_. Such errors are wrapped in `InstrumentedProcessDeathException`. Before processing the next request, the _instrumented process_ will be restarted automatically, but it can take some time.
+
+The extra logic of error and result handling depends on the provided instrumentation.
+
+## UtExecutionInstrumentation
+
+The next sections are related only to the `UtExecutionInstrumentation` passed to the _instrumented process_.
+
+The calling of `ConcreteExecutor::executeAsync` instantiated by the `UtExecutionInstrumentation`  can lead to the three possible situations:
+- `InstrumentedProcessDeathException` occurs. Usually, this situation means there is an internal issue in the _instrumented process_, but, nevertheless, this exception should be handled by the client. 
+- `InstrumentedProcessError`  occurs. It also means an internal issue and should be handled by the client. Sometimes it happens because the client provided the wrong configuration or parameters, but the _instrumented process_ **can't determine exactly** what's wrong with the client's data. The cause contains the description of the phase which threw the exception.
+- No exception occurs, so the `UtConcreteExecutionResult` is returned. It means that everything went well during the invocation or something broke down because of the wrong input, and the _instrumented process_ **knows exactly** what's wrong with the client's input. The _instrumented process_ guarantees that the state **is consistent**. The exact reason of failure is a `UtConcreteExecutionResult::result` field. It includes:
+	- `UtSandboxFailure` --- violation of permissions.
+	- `UtTimeoutException` --- the test execution time exceeds the provided time limit (`UtConcreteExecutionData::timeout`).
+	- `UtExecutionSuccess` --- the test executed successfully.
+	- `UtExplicitlyThrownException` --- the target method threw exception explicitly (via `throw` instruction).
+	- `UtImplicitlyThrownException` --- the target method threw exception implicitly (`NPE`, `OOB`, etc. or it was thrown inside the system library)
+	- etc.
+
+### How the error handling works
+
+The pipeline of the `UtExecutionInstrumentation::invoke` consists of 6 phases:
+-  `ValueConstructionPhase` --- constructs values from the models.
+- `PreparationPhase` --- prepares statics, etc.
+- `InvocationPhase` --- invokes the target method.
+- `StatisticsCollectionPhase` --- collects the coverage and execution-related data.
+- `ModelConstructionPhase` --- constructs the result models from the heap objects (`Any?`).
+- `PostprocessingPhase` --- restores statics, clear mocks, etc.
+
+Each phase can throw two kinds of exceptions:
+- `ExecutionPhaseStop` --- indicates that the phase want to stop the invocation of the pipeline completely, because it's already has a result. The returned result is the `ExecutionPhaseStop::result` field.
+- `ExecutionPhaseError` --- indicates that an unexpected error happened inside the phase execution, so it's rethrown to the main process.
+
+The `PhasesController::computeConcreteExecutionResult` then matches on the exception type and rethrows the exception if it's an `ExecutionPhaseError`, and returns the result if it's an `ExecutionPhaseStop`.
+
+###   Timeout
+
+There is a time limit on the concrete execution, so the  `UtExecutionInstrumentation::invoke` method must respect it. We wrap phases which can take a long time with the `executePhaseInTimeout` block, which internally keeps and updates the elapsed time. If any wrapped phase exceeds the timeout, we return the `TimeoutException` as the result of that phase.
+
+The clients cannot depend that cancellation request immediately breaks the invocation inside the _instrumented process_. The invocation is guaranteed to finish in the time of passed timeout. It may or **may not** finish earlier. Already started query in instrumented process is **uncancellable** - this is by design.
+
+Even if the `TimeoutException` occurs, the _instrumented process_ is ready to process new requests.  

utbot-core/src/main/kotlin/org/utbot/common/StopWatch.kt

@@ -52,7 +52,7 @@ class StopWatch {
         }
     }
 
-    fun get(unit: TimeUnit) = lock.withLockInterruptibly {
+    fun get(unit: TimeUnit = TimeUnit.MILLISECONDS) = lock.withLockInterruptibly {
         unsafeUpdate()
         unit.convert(elapsedMillis, TimeUnit.MILLISECONDS)
     }

utbot-framework-api/src/main/kotlin/org/utbot/framework/UtSettings.kt

@@ -277,7 +277,7 @@ object UtSettings : AbstractSettings(logger, defaultKeyForSettingsPath, defaultS
     /**
      * Timeout for specific concrete execution (in milliseconds).
      */
-    var concreteExecutionTimeoutInInstrumentedProcess: Long by getLongProperty(
+    var concreteExecutionDefaultTimeoutInInstrumentedProcessMillis: Long by getLongProperty(
         DEFAULT_EXECUTION_TIMEOUT_IN_INSTRUMENTED_PROCESS_MS
     )
 

utbot-framework-api/src/main/kotlin/org/utbot/framework/plugin/api/UtExecutionResult.kt

@@ -1,108 +1,108 @@
-package org.utbot.framework.plugin.api
-
-import org.utbot.framework.plugin.api.visible.UtStreamConsumingException
-import java.io.File
-import java.util.LinkedList
-
-sealed class UtExecutionResult
-
-data class UtExecutionSuccess(val model: UtModel) : UtExecutionResult() {
-    override fun toString() = "$model"
-}
-
-sealed class UtExecutionFailure : UtExecutionResult() {
-    abstract val exception: Throwable
-
-    /**
-     * Represents the most inner exception in the failure.
-     * Often equals to [exception], but is wrapped exception in [UtStreamConsumingException].
-     */
-    open val rootCauseException: Throwable
-        get() = exception
-}
-
-data class UtOverflowFailure(
-    override val exception: Throwable,
-) : UtExecutionFailure()
-
-data class UtSandboxFailure(
-    override val exception: Throwable
-) : UtExecutionFailure()
-
-data class UtStreamConsumingFailure(
-    override val exception: UtStreamConsumingException,
-) : UtExecutionFailure() {
-    override val rootCauseException: Throwable
-        get() = exception.innerExceptionOrAny
-}
-
-/**
- * unexpectedFail (when exceptions such as NPE, IOBE, etc. appear, but not thrown by a user, applies both for function under test and nested calls )
- * expectedCheckedThrow (when function under test or nested call explicitly says that checked exception could be thrown and throws it)
- * expectedUncheckedThrow (when there is a throw statement for unchecked exception inside of function under test)
- * unexpectedUncheckedThrow (in case when there is unchecked exception thrown from nested call)
- */
-data class UtExplicitlyThrownException(
-    override val exception: Throwable,
-    val fromNestedMethod: Boolean
-) : UtExecutionFailure()
-
-data class UtImplicitlyThrownException(
-    override val exception: Throwable,
-    val fromNestedMethod: Boolean
-) : UtExecutionFailure()
-
-class TimeoutException(s: String) : Exception(s)
-
-data class UtTimeoutException(override val exception: TimeoutException) : UtExecutionFailure()
-
-/**
- * Indicates failure in concrete execution.
- * For now it is explicitly throwing by ConcreteExecutor in case instrumented process death.
- */
-class ConcreteExecutionFailureException(cause: Throwable, errorFile: File, val processStdout: List<String>) :
-    Exception(
-        buildString {
-            appendLine()
-            appendLine("----------------------------------------")
-            appendLine("The instrumented process is dead")
-            appendLine("Cause:\n${cause.message}")
-            appendLine("Last 1000 lines of the error log ${errorFile.absolutePath}:")
-            appendLine("----------------------------------------")
-            errorFile.useLines { lines ->
-                val lastLines = LinkedList<String>()
-                for (line in lines) {
-                    lastLines.add(line)
-                    if (lastLines.size > 1000) {
-                        lastLines.removeFirst()
-                    }
-                }
-                lastLines.forEach { appendLine(it) }
-            }
-            appendLine("----------------------------------------")
-        },
-        cause
-    )
-
-data class UtConcreteExecutionFailure(override val exception: ConcreteExecutionFailureException) : UtExecutionFailure()
-
-val UtExecutionResult.isSuccess: Boolean
-    get() = this is UtExecutionSuccess
-
-val UtExecutionResult.isFailure: Boolean
-    get() = this is UtExecutionFailure
-
-inline fun UtExecutionResult.onSuccess(action: (model: UtModel) -> Unit): UtExecutionResult {
-    if (this is UtExecutionSuccess) action(model)
-    return this
-}
-
-inline fun UtExecutionResult.onFailure(action: (exception: Throwable) -> Unit): UtExecutionResult {
-    if (this is UtExecutionFailure) action(rootCauseException)
-    return this
-}
-
-fun UtExecutionResult.exceptionOrNull(): Throwable? = when (this) {
-    is UtExecutionFailure -> rootCauseException
-    is UtExecutionSuccess -> null
-}
+package org.utbot.framework.plugin.api
+
+import org.utbot.framework.plugin.api.visible.UtStreamConsumingException
+import java.io.File
+import java.util.LinkedList
+
+sealed class UtExecutionResult
+
+data class UtExecutionSuccess(val model: UtModel) : UtExecutionResult() {
+    override fun toString() = "$model"
+}
+
+sealed class UtExecutionFailure : UtExecutionResult() {
+    abstract val exception: Throwable
+
+    /**
+     * Represents the most inner exception in the failure.
+     * Often equals to [exception], but is wrapped exception in [UtStreamConsumingException].
+     */
+    open val rootCauseException: Throwable
+        get() = exception
+}
+
+data class UtOverflowFailure(
+    override val exception: Throwable,
+) : UtExecutionFailure()
+
+data class UtSandboxFailure(
+    override val exception: Throwable
+) : UtExecutionFailure()
+
+data class UtStreamConsumingFailure(
+    override val exception: UtStreamConsumingException,
+) : UtExecutionFailure() {
+    override val rootCauseException: Throwable
+        get() = exception.innerExceptionOrAny
+}
+
+/**
+ * unexpectedFail (when exceptions such as NPE, IOBE, etc. appear, but not thrown by a user, applies both for function under test and nested calls )
+ * expectedCheckedThrow (when function under test or nested call explicitly says that checked exception could be thrown and throws it)
+ * expectedUncheckedThrow (when there is a throw statement for unchecked exception inside of function under test)
+ * unexpectedUncheckedThrow (in case when there is unchecked exception thrown from nested call)
+ */
+data class UtExplicitlyThrownException(
+    override val exception: Throwable,
+    val fromNestedMethod: Boolean
+) : UtExecutionFailure()
+
+data class UtImplicitlyThrownException(
+    override val exception: Throwable,
+    val fromNestedMethod: Boolean
+) : UtExecutionFailure()
+
+class TimeoutException(s: String) : Exception(s)
+
+data class UtTimeoutException(override val exception: TimeoutException) : UtExecutionFailure()
+
+/**
+ * Indicates failure in concrete execution.
+ * For now it is explicitly throwing by ConcreteExecutor in case instrumented process death.
+ */
+class InstrumentedProcessDeathException(cause: Throwable, errorFile: File, val processStdout: List<String>) :
+    Exception(
+        buildString {
+            appendLine()
+            appendLine("----------------------------------------")
+            appendLine("The instrumented process is dead")
+            appendLine("Cause:\n${cause.message}")
+            appendLine("Last 1000 lines of the error log ${errorFile.absolutePath}:")
+            appendLine("----------------------------------------")
+            errorFile.useLines { lines ->
+                val lastLines = LinkedList<String>()
+                for (line in lines) {
+                    lastLines.add(line)
+                    if (lastLines.size > 1000) {
+                        lastLines.removeFirst()
+                    }
+                }
+                lastLines.forEach { appendLine(it) }
+            }
+            appendLine("----------------------------------------")
+        },
+        cause
+    )
+
+data class UtConcreteExecutionFailure(override val exception: InstrumentedProcessDeathException) : UtExecutionFailure()
+
+val UtExecutionResult.isSuccess: Boolean
+    get() = this is UtExecutionSuccess
+
+val UtExecutionResult.isFailure: Boolean
+    get() = this is UtExecutionFailure
+
+inline fun UtExecutionResult.onSuccess(action: (model: UtModel) -> Unit): UtExecutionResult {
+    if (this is UtExecutionSuccess) action(model)
+    return this
+}
+
+inline fun UtExecutionResult.onFailure(action: (exception: Throwable) -> Unit): UtExecutionResult {
+    if (this is UtExecutionFailure) action(rootCauseException)
+    return this
+}
+
+fun UtExecutionResult.exceptionOrNull(): Throwable? = when (this) {
+    is UtExecutionFailure -> rootCauseException
+    is UtExecutionSuccess -> null
+}

utbot-framework/src/main/kotlin/org/utbot/engine/Traverser.kt

@@ -7,6 +7,7 @@ import kotlinx.collections.immutable.persistentSetOf
 import kotlinx.collections.immutable.toPersistentList
 import kotlinx.collections.immutable.toPersistentMap
 import kotlinx.collections.immutable.toPersistentSet
+import mu.KotlinLogging
 import org.utbot.common.WorkaroundReason.HACK
 import org.utbot.framework.UtSettings.ignoreStaticsFromTrustedLibraries
 import org.utbot.common.WorkaroundReason.IGNORE_STATICS_FROM_TRUSTED_LIBRARIES
@@ -224,6 +225,7 @@ import java.lang.reflect.TypeVariable
 import java.lang.reflect.WildcardType
 
 private val CAUGHT_EXCEPTION = LocalVariable("@caughtexception")
+private val logger = KotlinLogging.logger {}
 
 class Traverser(
     private val methodUnderTest: ExecutableId,