Spock generates assertion reports with a changed state of object
Describe the bug
It seems that the assertion report from the expectation block is generated with a delay, rather than exactly when the verified expectation is not met. I am referring to the following example report of a mismatch between the expected value and the current value:
Condition not satisfied:
expectedValue == actualValue
| | |
123 | 124
false
In my functional tests, I use the concept of drivers, which separate the implementation details of tests from the test case, allowing for clear tests even for non-technical people. These drivers are directly involved in verifying expectations by providing relevant details that help investigate why an expectation was not met in a given test case. This includes information about recently executed commands, environment variables, and anything else that could affect the fulfillment of expectations. A very useful and clear solution.
Consider the following test case:
class ExampleTest extends Specification {
@TempDir File cwd
def driver = new CommandDriver(cwd)
def cleanup() {
driver.execute('rm', '-rf', 'exampleDir')
}
def 'example test'() {
when:
driver.execute('mkdir', 'exampleDir')
then:
driver.execute('ls', '-al').text.contains('exampleDirzzz') // Deliberately unmet expectations
}
}
As you can see, the expectation block is deliberately unfulfilled. I did this to show what the problem is. This is what the implementation of the sample driver looks like:
class CommandDriver {
private ProcessBuilder builder
private Process process
final File currentWorkingDir
CommandDriver(File currentWorkingDir) {
this.currentWorkingDir = currentWorkingDir
}
Process execute(String... command) {
builder = createProcessBuilder(command)
process = builder.start()
process.waitFor()
return process
}
@Override
String toString() {
def description = 'Command Driver'
if (builder) {
description += [
'',
"- current working directory: ${builder.directory()}",
'- command arguments:',
builder.command().collect { " - ${it}" },
].flatten().join(System.lineSeparator())
}
return description
}
protected ProcessBuilder createProcessBuilder(String... command) {
def builder = new ProcessBuilder()
.directory(currentWorkingDir)
.command(command)
.redirectErrorStream(true)
return builder
}
}
As you can see, in the toString() method, I display all the information that is useful for diagnosis. The report from the above test case looks like this:
Condition not satisfied:
driver.execute('ls', '-al').text.contains('exampleDirzzz')
| | | |
| | | false
| | total 0
| | drwx------. 3 piotrek piotrek 60 06-06 14:00 .
| | drwxrwxrwt. 47 root root 1240 06-06 14:00 ..
| | drwxr-xr-x. 2 piotrek piotrek 40 06-06 14:00 exampleDir
| Process[pid=533728, exitValue=0]
Command Driver
- current working directory: /tmp/spock_example_test_0_cwd16680776575184356238
- command arguments:
- rm
- -rf
- exampleDir
The problem is in the command arguments: section, where ls -al (from the expectations block) should appear, but instead rm -rf exampleDir (from the cleanup method) appears.
This confirms my thesis from the beginning of this report. Spock generates a report with a delay. In my opinion, this is very problematic because it does not show the state that caused expectation not to be fulfilled. Between this block and the generation of the report, the state of the verified object, as in my case, may change.
To Reproduce
I am posting a project that illustrates this problem: spock-state.tar.gz
Expected behavior
The state presented in the report on unfulfilled expectations should be exactly the same as at the time of verification of this expectation.
Actual behavior
The changed state of objects is presented in the report on unmet expectations.
Java version
openjdk version "11.0.27" 2025-04-15 OpenJDK Runtime Environment Temurin-11.0.27+6 (build 11.0.27+6) OpenJDK 64-Bit Server VM Temurin-11.0.27+6 (build 11.0.27+6, mixed mode)
Buildtool version
Gradle 8.6
Build time: 2024-02-02 16:47:16 UTC Revision: d55c486870a0dc6f6278f53d21381396d0741c6e
Kotlin: 1.9.20 Groovy: 3.0.17 Ant: Apache Ant(TM) version 1.10.13 compiled on January 4 2023 JVM: 11.0.27 (Eclipse Adoptium 11.0.27+6) OS: Linux 6.14.9-200.fc41.x86_64 amd64
What operating system are you using
Linux
Dependencies
testRuntimeClasspath - Runtime classpath of source set 'test'.
+--- org.spockframework:spock-core:2.4-M6-groovy-3.0
| +--- org.codehaus.groovy:groovy:3.0.24
| +--- io.leangen.geantyref:geantyref:1.3.16
| +--- org.spockframework:spock-bom:2.4-M6-groovy-3.0
| | \--- org.spockframework:spock-core:2.4-M6-groovy-3.0 (c)
| +--- org.junit:junit-bom:5.12.2
| | +--- org.junit.platform:junit-platform-engine:1.12.2 (c)
| | +--- org.junit.platform:junit-platform-launcher:1.12.2 (c)
| | \--- org.junit.platform:junit-platform-commons:1.12.2 (c)
| +--- org.junit.platform:junit-platform-engine -> 1.12.2
| | +--- org.junit:junit-bom:5.12.2 (*)
| | +--- org.opentest4j:opentest4j:1.3.0
| | \--- org.junit.platform:junit-platform-commons:1.12.2
| | \--- org.junit:junit-bom:5.12.2 (*)
| \--- org.hamcrest:hamcrest:3.0
\--- org.junit.platform:junit-platform-launcher -> 1.12.2
+--- org.junit:junit-bom:5.12.2 (*)
\--- org.junit.platform:junit-platform-engine:1.12.2 (*)
Additional context
No response
Below is another, much simpler example. All in all, I don't know what to think about it now.
class ExampleTest extends Specification {
def 'another example'() {
given:
def state = new State()
when:
state.value = 123
then:
state.value == 124
cleanup:
state.value = 125
}
static class State {
def value
@Override
String toString() {
return value as String
}
}
}
This is a test report:
Condition not satisfied:
state.value == 124
| | |
125 123 false
That's not so much a bug, more a performance optimization, besides that there is literally no way to get the behavior you expect.
For example consider this even simpler example:
import java.util.concurrent.atomic.AtomicInteger
class ExampleTest extends Specification {
def 'another example'() {
given:
def i = new AtomicInteger(123)
expect:
i.andIncrement == 125
}
}
which outputs
Condition not satisfied:
i.andIncrement == 125
| | |
| 123 false
124
So the stimulus already modifies the state of the SUT.
The assertion error is only created when the == fails, so even if the condition rendering would be created at that time, it would already be "wrong".
So to get a more correct result, you would need to create the rendering for each step, before the next step is executed, so the rendering for i needs to be done before the getAndIncrement is called for example.
And this needs to be done, whether the rendering will be needed or not, because at that point you cannot know whether the rendering will be needed or not.
Creating all these renderings up-front would be a performance nightmare as some of the renderings are also quite expensive to calculate.
And even then, it could produce wrong results or even worse wrong test results, if for example the toString call or whatever is used for the rendering (this is different for different types) could already modify the state, so the state would change before the assertion is checked so the test framework would influence the result and that should never happen.
The rendering is delayed until it is actually needed, that is until the assertion message is going to be printed to console or some report file the first time and then cached.
Actually, I had a similar situation in the past. I tested some CDI beans with Spock. And by the time the condition rendering happened, the CDI container was already shut down and thus the proxies that were used for the rendering were not valid anymore and couldn't be rendered properly.
I there decided to sacrifice a bit of performance by eagerly rendering the conditions after the feature method finished using this simple extension: https://github.com/Vampire/command-framework/blob/master/src/spock/java/net/kautler/test/spock/EagerExceptionRenderer.java
This would actually not fully help in your concrete examples, as the cleanup: block is part of the feature method and thus the rendering would still be too late.
If the cleanup would have been in a cleanup method it would have helped though.
What might help in your case is to register an IRunListener to the specs in the extension and then do the eager rendering in the error method. I think that method should be called as soon as the error happened, so before a cleanup: block would change the state.
Of course the other things mentioned would still apply, so the example I wrote above would still print the same output as that is the state at the time the failure happens.
Thank you very much for your detailed description of the problem. Thank you also for suggesting possible solutions for my case. I will definitely try to do something with the implementation of the IRunListener interface.
The following code solves the problem. Thanks again @Vampire.
@CompileStatic
class EarlyRenderRunListener extends AbstractRunListener {
@Override
void error(ErrorInfo error) {
if (error.exception instanceof ConditionNotSatisfiedError) {
// force early render of the error message about not satisfied condition
(error.exception as ConditionNotSatisfiedError).condition.rendering
}
}
}
Question: could this behavior be part of Spock's standard behavior?
You can just "toString" all exceptions, no need to type-check and access internals.
Besides that, whether it will go into Spock @leonard84 has to decide, but I doubt it should. As I just explained, even with that behavior you don't get your expected behavior in all cases, and it is an intentional behavior to not render the cause prematurely, as it might not be use later and can be quite expensive to calculate.
Thanks @Vampire, for the detailed answer and for providing a workaround. I agree with your reasoning about not changing anything in Spock.