Skip to content

Conversation

@OsaSoft
Copy link
Contributor

@OsaSoft OsaSoft commented Oct 23, 2025

Problem decription:

After upgrading to a newer version I noticed a LOT of spamming in the console logs, enough to significantly slow down test execution and even crash the IDE. After some research I narrowed it down to this PR: #1395

The issue I encountered is caused by a combination of these factors:

  • using property based testing (many generated test cases)
  • verifying different calls to the same mock
  • the change to withArg and withNullableArg dumping the error stack trace on any failed match, even if the test itself passes

Proposed solution:

Add an argument flag to the withArg and withNullableArg functions to toggle the stacktrace dump behaviour

Reproduction:

build.gradle.kts

import org.gradle.internal.impldep.org.junit.runner.Request.runner
import org.jetbrains.kotlin.gradle.plugin.KotlinPlatformType

plugins {
    kotlin("jvm") version "2.2.20"
}

group = "org.example"
version = "1.0-SNAPSHOT"

repositories {
    mavenCentral()
    mavenLocal()
}

dependencies {
    testImplementation(kotlin("test"))

    testImplementation("io.kotest:kotest-assertions-core:6.0.3")
    testImplementation("io.kotest:kotest-assertions-core-jvm:6.0.3")
    testImplementation("io.kotest:kotest-property:6.0.3")
    testImplementation("io.kotest:kotest-framework-engine-jvm:6.0.3")
    testImplementation("io.kotest:kotest-runner-junit5:6.0.3")

    testImplementation("io.mockk:mockk:1.14.7-SNAPSHOT-local")
}

tasks.test {
    useJUnitPlatform()
}
kotlin {
    jvmToolchain(21)
}

Foo.kt

package cloud.osasoft.mockkTest

interface Bar {
    fun doSomething(number: Int)
}

class Foo(private val bar: Bar) {

    fun fooBar(a: Int, b: Int) {
        bar.doSomething(a)
        bar.doSomething(b)
    }
}

FooSpec.kt

package cloud.osasoft.mockkTest

import io.kotest.assertions.shouldFail
import io.kotest.core.spec.style.FreeSpec
import io.kotest.matchers.ints.shouldBeLessThan
import io.kotest.matchers.shouldBe
import io.kotest.property.Arb
import io.kotest.property.arbitrary.int
import io.kotest.property.arbitrary.positiveInt
import io.kotest.property.checkAll
import io.mockk.mockk
import io.mockk.verify

class FooSpec : FreeSpec(
    {
        "This spams log a lot" {
            checkAll(
                Arb.int(1..10),
                Arb.int(1..10),
            ) { a, b ->
                val bar = mockk<Bar>(relaxed = true)
                val foo = Foo(bar)

                foo.fooBar(a, b)
                verify {
                    bar.doSomething(
                        withArg { it shouldBe a }
                    )
                    bar.doSomething(
                        withArg { it shouldBe b }
                    )
                }
            }
        }

        "This does not spam and successfully passes" {
            checkAll(
                Arb.int(),
                Arb.int(),
            ) { a, b ->
                val bar = mockk<Bar>(relaxed = true)
                val foo = Foo(bar)

                foo.fooBar(a, b)

                verify {
                    bar.doSomething(
                        withArg(logAllAssertionErrors = false) { it shouldBe a }
                    )
                    bar.doSomething(
                        withArg(logAllAssertionErrors = false) { it shouldBe b }
                    )
                }
            }
        }

        "This does not spam and fails" {
            checkAll(
                Arb.positiveInt(),
                Arb.positiveInt(),
            ) { a, b ->
                shouldFail {
                    val bar = mockk<Bar>(relaxed = true)
                    val foo = Foo(bar)

                    foo.fooBar(a, b)

                    verify {
                        bar.doSomething(
                            withArg(logAllAssertionErrors = false) { it shouldBe a }
                        )
                        bar.doSomething(
                            withArg(logAllAssertionErrors = false) { it shouldBe b }
                        )
                        bar.doSomething(
                            withArg(logAllAssertionErrors = false) {
                                // This will fail
                                it shouldBeLessThan 0
                            }
                        )
                    }
                }
            }
        }
    }
)

Here the first testcase spams the console with messages like this:
image

Possible future improvements:

Would be nice if the behaviour could be configured project-wise via mockk config (would love some pointers on how to achieve this).
Would be nice if the stacktrace dump actually used a logger instead of directly dumping to console.

@Raibaz
Copy link
Collaborator

Raibaz commented Oct 23, 2025

Thanks for the investigation!

What if instead of just passing a flag to turn on/off the printStackTrace calls we gave the option to pass a java.util.logging.Logger to use to log the stacktraces?

That would also solve at least one of the future improvements you identified.

@OsaSoft
Copy link
Contributor Author

OsaSoft commented Oct 24, 2025

Hi @Raibaz . Thats an interesting idea. How do you think we should handle the default there to maintain the current functionality? Nullable with default null, and if its null keep current behaviour, otherwise use the provided logger? Should we use a WARN or maybe even INFO level?

Or it could be something like this, that way when we dont want any logging, we can even completely skip the logger overhead, which for a lot of larger strings (like in this case) can actually have a noticable impact and we can leave it up to the user to use whatever log level they deem appropriate
assertionErrorLogger: (AssertionError) -> Unit = { e -> e.printStackTrace() },

then we could call the function e.g. like this:

withArg(assertionErrorLogger = logger::debug) {
  a shouldBe b
}

edit: actually that wouldnt work, since the receiver param would be the assertionError 🤔 would work with a String so then in the matcher we would have to call it with the exception converted to string, but that could lose the exception instance, if we wanted e.g. to log it like logger.error("Failed matching arg", ex)

@Raibaz
Copy link
Collaborator

Raibaz commented Oct 24, 2025

Uhm, why wouldn't it work?

We could implement the FunctionMatcher class like this:

data class FunctionMatcher<in T : Any>(
    val matchingFunc: (T) -> Boolean,
    override val argumentType: KClass<*>,
    private val assertionErrorLogger: (AssertionError) -> Unit = {e -> e.printStackTrace()}, // Existing behavior by default
) : Matcher<T>, TypedMatcher, EquivalentMatcher {
    override fun equivalent(): Matcher<Any> = ConstantMatcher(true)

    override fun match(arg: T?): Boolean {
        return if (arg == null) {
            false
        } else {
            try {
                matchingFunc(arg)
            } catch (a: AssertionError) {
                assertionErrorLogger();
                false
            }
        }
    }

And change the withArg function to accept a (AssertionError) -> Unit param to be relayed to the FunctionMatcher.

I quite like it, as it offer good customizability; I actually like it way more than just passing a logger.

@OsaSoft
Copy link
Contributor Author

OsaSoft commented Oct 27, 2025

i meant that a very short and clean reference pass wouldnt work, ie withArg(assertionErrorLogger = logger::debug), but yeah, with lambda bodies it should work fine. Let me do a few quick tests, see what works best for a nice syntax and ill get back to you once i push the changes

@OsaSoft
Copy link
Contributor Author

OsaSoft commented Oct 27, 2025

ok, so i think this signature works quite well, some example usages

// quiet
withArg({}) { it shouldBe a }

// logger
withArg({ logger.debug(it) }) { it shouldBe a}

// custom reference
withArg(::logAssertion) { it shouldBe a }
fun logAssertion(error: AssertionError) = ...

one more thing Im considering: since right now the default function body is defined the same in quite a few places, could it be moved to possibly some static value? Where could this go, is there some file containing different util functions etc? Or maybe some config class that could be a good place to put it?

@Raibaz
Copy link
Collaborator

Raibaz commented Oct 28, 2025

Can you please run gradle :mockk-dsl:apiDump to update the api definition files and make the builds pass?

@OsaSoft
Copy link
Contributor Author

OsaSoft commented Oct 28, 2025

ok, should be done. Thanks for letting me know which exactly to run :)

@Raibaz Raibaz merged commit 00ea4a8 into mockk:master Oct 29, 2025
22 checks passed
@Raibaz
Copy link
Collaborator

Raibaz commented Oct 29, 2025

Thanks!

*
* @param logAllAssertionErrors if true, all assertion errors inside the captureBlock will be logged.
* This can cause multiple errors to be logged if the matcher is evaluated
* multiple times.
Copy link

Choose a reason for hiding this comment

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

This doesn't match the actual parameter of the method?

* @return the captured argument
*/
inline fun <reified T : Any> withArg(
noinline assertionErrorLogger: (AssertionError) -> Unit = { e -> e.printStackTrace() },
Copy link

@hho hho Dec 15, 2025

Choose a reason for hiding this comment

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

This breaks compilation for uses of withArg with a variable (instead of a direct given block)...

Copy link
Contributor Author

Choose a reason for hiding this comment

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

@hho can you provide an example please?

Copy link

Choose a reason for hiding this comment

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

Sure. Here's what broke for me (only anonymized):

Screenshot 2025-12-16 at 00 07 50

My capture block is extracted into the someDetailValidator variable. This worked fine in 1.14.6, but breaks in 1.14.7, because now I need to either pass an assertionErrorLogger or spell out the captureBlock parameter name.

I think the problem might've be avoidable, if the new signatures (with the new assertionErrorLogger parameter) would've just been added as separate methods, without a default for the logger?

@hho
Copy link

hho commented Dec 15, 2025

Maybe I don't completely understand what's going on here, but I believe such a breaking API change shouldn't be hidden in a patch release?

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

3 participants