Skip to content
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

Execution results are presented in case of any failure #314

Merged
merged 7 commits into from
May 2, 2024
Merged
Show file tree
Hide file tree
Changes from 2 commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
115 changes: 74 additions & 41 deletions src/jvm/main/org/jetbrains/kotlinx/lincheck/Reporter.kt
Original file line number Diff line number Diff line change
Expand Up @@ -283,21 +283,21 @@ internal fun StringBuilder.appendExecutionScenario(

private data class ActorWithResult(
val actor: Actor,
val result: Result,
val result: Result?,
val clock: HBClock? = null,
val exceptionInfo: ExceptionNumberAndStacktrace? = null
) {
init {
require(exceptionInfo == null || result is ExceptionResult)
}

constructor(actor: Actor, result: Result,
constructor(actor: Actor, result: Result?,
exceptionStackTraces: Map<Throwable, ExceptionNumberAndStacktrace>,
clock: HBClock? = null,
) : this(actor, result, clock, result.exceptionInfo(exceptionStackTraces))
) : this(actor, result, clock, result?.exceptionInfo(exceptionStackTraces))

override fun toString(): String =
"${actor}: $result" +
"${actor}${result?.let { ": $it" } ?: ""}" +
(exceptionInfo?.let { " #${it.number}" } ?: "") +
(clock?.takeIf { !it.empty }?.let { " $it" } ?: "")

Expand All @@ -311,62 +311,74 @@ private fun<T, U> requireEqualSize(x: List<T>, y: List<U>, lazyMessage: () -> St
}

internal fun StringBuilder.appendExecutionScenarioWithResults(
scenario: ExecutionScenario,
executionResult: ExecutionResult,
failure: LincheckFailure,
exceptionStackTraces: Map<Throwable, ExceptionNumberAndStacktrace>,
): StringBuilder {
requireEqualSize(scenario.parallelExecution, executionResult.parallelResults) {
val scenario = failure.scenario
val executionResults = failure.results
val initResults = executionResults.initResults.fillWithNullsToSize(scenario.initExecution.size)
val parallelResultsWithClock = executionResults.parallelResultsWithClock.zip(scenario.parallelExecution).map { (threadResults, actors) ->
threadResults.fillWithNullsToSize(actors.size)
}
val postResults = executionResults.postResults.fillWithNullsToSize(scenario.postExecution.size)

requireEqualSize(scenario.parallelExecution, parallelResultsWithClock) {
"Different numbers of threads and matching results found"
}
requireEqualSize(scenario.initExecution, executionResult.initResults) {
requireEqualSize(scenario.initExecution, initResults) {
"Different numbers of actors and matching results found"
}
requireEqualSize(scenario.postExecution, executionResult.postResults) {
requireEqualSize(scenario.postExecution, postResults) {
"Different numbers of actors and matching results found"
}
for (i in scenario.parallelExecution.indices) {
requireEqualSize(scenario.parallelExecution[i], executionResult.parallelResults[i]) {
requireEqualSize(scenario.parallelExecution[i], parallelResultsWithClock[i]) {
"Different numbers of actors and matching results found"
}
}
val initPart = scenario.initExecution.zip(executionResult.initResults) {
val initPart = scenario.initExecution.zip(initResults) {
actor, result -> ActorWithResult(actor, result, exceptionStackTraces).toString()
}
val postPart = scenario.postExecution.zip(executionResult.postResults) {
val postPart = scenario.postExecution.zip(postResults) {
actor, result -> ActorWithResult(actor, result, exceptionStackTraces).toString()
}
var hasClocks = false
val hasClocks = failure is IncorrectResultsFailure && parallelResultsWithClock.any { threadResults -> threadResults.any { it?.clockOnStart?.empty != true } }
avpotapov00 marked this conversation as resolved.
Show resolved Hide resolved
val parallelPart = scenario.parallelExecution.mapIndexed { i, actors ->
actors.zip(executionResult.parallelResultsWithClock[i]) { actor, resultWithClock ->
if (!resultWithClock.clockOnStart.empty)
hasClocks = true
ActorWithResult(actor, resultWithClock.result, exceptionStackTraces, clock = resultWithClock.clockOnStart).toString()
actors.zip(parallelResultsWithClock[i]) { actor, resultWithClock ->
ActorWithResult(actor, resultWithClock?.result, exceptionStackTraces, clock = if (hasClocks) resultWithClock?.clockOnStart else null).toString()
}
}
with(ExecutionLayout(initPart, parallelPart, postPart, validationFunctionName = null)) {
val validationFunctionName = if (failure is ValidationFailure) {
scenario.validationFunction?.let { "${it.method.name}(): ${failure.exception::class.simpleName}" }
} else null
with(ExecutionLayout(initPart, parallelPart, postPart, validationFunctionName)) {
appendSeparatorLine()
appendHeader()
appendSeparatorLine()
if (initPart.isNotEmpty()) {
appendColumn(0, initPart)
appendSeparatorLine()
}
if (executionResult.afterInitStateRepresentation != null) {
appendWrappedLine("STATE: ${executionResult.afterInitStateRepresentation}")
if (executionResults.afterInitStateRepresentation != null) {
appendWrappedLine("STATE: ${executionResults.afterInitStateRepresentation}")
appendSeparatorLine()
}
appendColumns(parallelPart)
appendSeparatorLine()
if (executionResult.afterParallelStateRepresentation != null) {
appendWrappedLine("STATE: ${executionResult.afterParallelStateRepresentation}")
if (executionResults.afterParallelStateRepresentation != null) {
appendWrappedLine("STATE: ${executionResults.afterParallelStateRepresentation}")
appendSeparatorLine()
}
if (postPart.isNotEmpty()) {
appendColumn(0, postPart)
appendSeparatorLine()
}
if (executionResult.afterPostStateRepresentation != null && postPart.isNotEmpty()) {
appendWrappedLine("STATE: ${executionResult.afterPostStateRepresentation}")
if (executionResults.afterPostStateRepresentation != null && postPart.isNotEmpty()) {
appendWrappedLine("STATE: ${executionResults.afterPostStateRepresentation}")
appendSeparatorLine()
}
if (validationFunctionName != null) {
appendToFirstColumn(validationFunctionName)
appendSeparatorLine()
}
}
Expand Down Expand Up @@ -397,10 +409,17 @@ internal fun StringBuilder.appendExecutionScenarioWithResults(
return this
}

private fun <T> List<T>.fillWithNullsToSize(requiredSize: Int): List<T?> {
avpotapov00 marked this conversation as resolved.
Show resolved Hide resolved
val result = mutableListOf<T?>()
forEach { result += it }
repeat(requiredSize - size) { result += null }
return result
}

internal fun StringBuilder.appendFailure(failure: LincheckFailure): StringBuilder {
val results: ExecutionResult? = (failure as? IncorrectResultsFailure)?.results
val results: ExecutionResult = failure.results
// If a result is present - collect exceptions stack traces to print them
val exceptionStackTraces: Map<Throwable, ExceptionNumberAndStacktrace> = results?.let {
val exceptionStackTraces: Map<Throwable, ExceptionNumberAndStacktrace> = results.let {
when (val exceptionsProcessingResult = collectExceptionStackTraces(results)) {
// If some exception was thrown from the Lincheck itself, we ask for bug reporting
is InternalLincheckBugResult -> {
Expand All @@ -410,17 +429,17 @@ internal fun StringBuilder.appendFailure(failure: LincheckFailure): StringBuilde

is ExceptionStackTracesResult -> exceptionsProcessingResult.exceptionStackTraces
}
} ?: emptyMap()
}

when (failure) {
is IncorrectResultsFailure -> appendIncorrectResultsFailure(failure, exceptionStackTraces)
is DeadlockOrLivelockFailure -> appendDeadlockWithDumpFailure(failure)
is UnexpectedExceptionFailure -> appendUnexpectedExceptionFailure(failure)
is DeadlockOrLivelockFailure -> appendDeadlockWithDumpFailure(failure, exceptionStackTraces)
is UnexpectedExceptionFailure -> appendUnexpectedExceptionFailure(failure, exceptionStackTraces)
is ValidationFailure -> when (failure.exception) {
is LincheckInternalBugException -> appendInternalLincheckBugFailure(failure.exception)
else -> appendValidationFailure(failure)
else -> appendValidationFailure(failure, exceptionStackTraces)
}
is ObstructionFreedomViolationFailure -> appendObstructionFreedomViolationFailure(failure)
is ObstructionFreedomViolationFailure -> appendObstructionFreedomViolationFailure(failure, exceptionStackTraces)
}
if (failure.trace != null) {
appendLine()
Expand Down Expand Up @@ -452,7 +471,9 @@ internal fun StringBuilder.appendExceptionsStackTraces(exceptionStackTraces: Map
return this
}

fun StringBuilder.appendInternalLincheckBugFailure(exception: Throwable) {
private fun StringBuilder.appendInternalLincheckBugFailure(
exception: Throwable,
) {
appendLine(
"""
Wow! You've caught a bug in Lincheck.
Expand Down Expand Up @@ -556,17 +577,23 @@ internal fun collectExceptionStackTraces(executionResult: ExecutionResult): Exce
return ExceptionStackTracesResult(exceptionStackTraces)
}

private fun StringBuilder.appendUnexpectedExceptionFailure(failure: UnexpectedExceptionFailure): StringBuilder {
private fun StringBuilder.appendUnexpectedExceptionFailure(
failure: UnexpectedExceptionFailure,
exceptionStackTraces: Map<Throwable, ExceptionNumberAndStacktrace>
): StringBuilder {
appendLine("= The execution failed with an unexpected exception =")
appendExecutionScenario(failure.scenario)
appendExecutionScenarioWithResults(failure, exceptionStackTraces)
appendLine()
appendException(failure.exception)
return this
}

private fun StringBuilder.appendDeadlockWithDumpFailure(failure: DeadlockOrLivelockFailure): StringBuilder {
private fun StringBuilder.appendDeadlockWithDumpFailure(
failure: DeadlockOrLivelockFailure,
exceptionStackTraces: Map<Throwable, ExceptionNumberAndStacktrace>
): StringBuilder {
appendLine("= The execution has hung, see the thread dump =")
appendExecutionScenario(failure.scenario)
appendExecutionScenarioWithResults(failure, exceptionStackTraces)
appendLine()
// We don't save thread dump in model checking mode, for now it is present only in stress testing
failure.threadDump?.let { threadDump ->
Expand Down Expand Up @@ -604,7 +631,7 @@ private fun StringBuilder.appendIncorrectResultsFailure(
exceptionStackTraces: Map<Throwable, ExceptionNumberAndStacktrace>,
): StringBuilder {
appendLine("= Invalid execution results =")
appendExecutionScenarioWithResults(failure.scenario, failure.results, exceptionStackTraces)
appendExecutionScenarioWithResults(failure, exceptionStackTraces)
return this
}

Expand All @@ -614,18 +641,24 @@ private fun StringBuilder.appendHints(hints: List<String>) {
}
}

private fun StringBuilder.appendValidationFailure(failure: ValidationFailure): StringBuilder {
private fun StringBuilder.appendValidationFailure(
failure: ValidationFailure,
exceptionStackTraces: Map<Throwable, ExceptionNumberAndStacktrace>
): StringBuilder {
appendLine("= Validation function ${failure.validationFunctionName} has failed =")
appendExecutionScenario(failure.scenario, showValidationFunctions = true)
appendExecutionScenarioWithResults(failure, exceptionStackTraces)
appendln()
appendln()
appendException(failure.exception)
return this
}

private fun StringBuilder.appendObstructionFreedomViolationFailure(failure: ObstructionFreedomViolationFailure): StringBuilder {
private fun StringBuilder.appendObstructionFreedomViolationFailure(
failure: ObstructionFreedomViolationFailure,
exceptionStackTraces: Map<Throwable, ExceptionNumberAndStacktrace>
): StringBuilder {
appendLine("= ${failure.reason} =")
appendExecutionScenario(failure.scenario)
appendExecutionScenarioWithResults(failure, exceptionStackTraces)
return this
}

Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -13,7 +13,9 @@ import org.jetbrains.kotlinx.lincheck.*

/**
* This class represents a result of [ExecutionScenario] execution.
* All the result parts should have the same dimensions as the scenario.
* If the execution is completed, all the result parts should have the exact dimensions of the scenario.
avpotapov00 marked this conversation as resolved.
Show resolved Hide resolved
* However, in case there were some unfinished actors, the size of the [initResults], [parallelResultsWithClock],
* and [postResults] may be less than in the scenario.
*/
data class ExecutionResult(
/**
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -27,20 +27,22 @@ class CompletedInvocationResult(
/**
* Indicates that the invocation has run into deadlock or livelock found by [ManagedStrategy].
*/
data object ManagedDeadlockInvocationResult : InvocationResult()
class ManagedDeadlockInvocationResult(val results: ExecutionResult) : InvocationResult()
Copy link
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Now that all invocation results contain results field, let's propagate this field to the parent class InvocationResult.

Copy link
Collaborator Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

No, take a look at
data object SpinCycleFoundAndReplayRequired: InvocationResult():
it doesn't contain results

Copy link
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

So let's change it to also contain results?)

Then it would be uniform, no special cases, no needs to do type-casts and type-checks (i.e. result is CompletedInvocationResult) when we want to access results field, etc.


/**
* The invocation was not completed after timeout and runner halted the execution.
*/
class RunnerTimeoutInvocationResult(
val threadDump: Map<Thread, Array<StackTraceElement>>,
val results: ExecutionResult
): InvocationResult()

/**
* The invocation has completed with an unexpected exception.
*/
class UnexpectedExceptionInvocationResult(
val exception: Throwable
val exception: Throwable,
val results: ExecutionResult
) : InvocationResult()

/**
Expand All @@ -50,18 +52,20 @@ class UnexpectedExceptionInvocationResult(
*/
class ValidationFailureInvocationResult(
val scenario: ExecutionScenario,
val exception: Throwable
val exception: Throwable,
val results: ExecutionResult
) : InvocationResult()

/**
* Obstruction freedom check is requested,
* but an invocation that hangs has been found.
*/
class ObstructionFreedomViolationInvocationResult(
val reason: String
val reason: String,
val results: ExecutionResult
) : InvocationResult()

/**
* Indicates that spin-cycle has been found for the first time and replay of current interleaving is required.
*/
object SpinCycleFoundAndReplayRequired: InvocationResult()
data object SpinCycleFoundAndReplayRequired: InvocationResult()
Original file line number Diff line number Diff line change
Expand Up @@ -308,35 +308,53 @@ internal open class ParallelThreadsRunner(
executor.submitAndAwait(arrayOf(validationPart), timeout)
val validationResult = validationPart.results.single()
if (validationResult is ExceptionResult) {
return ValidationFailureInvocationResult(scenario, validationResult.throwable)
return ValidationFailureInvocationResult(scenario, validationResult.throwable, collectExecutionResults())
}
}
// Combine the results and convert them for the standard class loader (if they are of non-primitive types).
// We do not want the transformed code to be reachable outside of the runner and strategy classes.
return CompletedInvocationResult(
ExecutionResult(
initResults = initialPartExecution?.results?.toList().orEmpty(),
parallelResultsWithClock = parallelPartExecutions.map { execution ->
execution.results.zip(execution.clocks).map {
ResultWithClock(it.first, HBClock(it.second.clone()))
}
},
postResults = postPartExecution?.results?.toList().orEmpty(),
afterInitStateRepresentation = afterInitStateRepresentation,
afterParallelStateRepresentation = afterParallelStateRepresentation,
afterPostStateRepresentation = afterPostStateRepresentation
)
)
return CompletedInvocationResult(collectExecutionResults(afterInitStateRepresentation, afterParallelStateRepresentation, afterPostStateRepresentation))
} catch (e: TimeoutException) {
val threadDump = collectThreadDump(this)
return RunnerTimeoutInvocationResult(threadDump)
return RunnerTimeoutInvocationResult(threadDump, collectExecutionResults())
} catch (e: ExecutionException) {
return UnexpectedExceptionInvocationResult(e.cause!!)
return UnexpectedExceptionInvocationResult(e.cause!!, collectExecutionResults())
} finally {
resetState()
}
}

/**
* This method is called when we have some execution result other than [CompletedInvocationResult].
*/
fun collectExecutionResults(): ExecutionResult {
return collectExecutionResults(null, null, null)
}

private fun collectExecutionResults(
afterInitStateRepresentation: String?,
afterParallelStateRepresentation: String?,
afterPostStateRepresentation: String?
): ExecutionResult {
// We also collect results in case when some actors have not finished due to some reasons
// (execution has hung or unexpected exception).
// Therefore, some results may be null as corresponding actors won't finish.
// To process them correctly and pass only ready results, we do `takeWhile { it != null }` to cut off
// suffix with `null` results.
return ExecutionResult(
initResults = initialPartExecution?.results?.toList()?.takeWhile { it != null }.orEmpty(),
avpotapov00 marked this conversation as resolved.
Show resolved Hide resolved
parallelResultsWithClock = parallelPartExecutions.map { execution ->
execution.results.takeWhile { it != null }.zip(execution.clocks).map {
ResultWithClock(it.first, HBClock(it.second.clone()))
}
},
postResults = postPartExecution?.results?.toList()?.takeWhile { it != null }.orEmpty(),
afterInitStateRepresentation = afterInitStateRepresentation,
afterParallelStateRepresentation = afterParallelStateRepresentation,
afterPostStateRepresentation = afterPostStateRepresentation
)
}


private fun createInitialPartExecution() =
if (scenario.initExecution.isNotEmpty()) {
Expand Down
Loading