Wrong assert displayed as failing when having a failing assert
9 views
Skip to first unread message
Steinar Bang
Jun 4, 2023, 12:53:28 PM6/4/23
to op...@googlegroups.com
Platform: debian 11.7 "bullseye", amd64
openjdk-17-jdk:amd64 17.0.6+10-1~deb11u1 (ie. java 17)
karaf 4.4.3
pax-exam 4.13.5
eclipse 2023-03 (4.27.0)
What I usually do when creating JUnit tests is to run in a
red-green-red-green... rythm, the way Martin Fowler taught me.
I.e. I create the test first to be failing and then I make the test
green, create a new failure situation, fix the failure to make the test
green and so on.
When doing this on a pax exam test I saw some weird behaviour: the first
assert in the test was failing, and when I changed the expected value to
satisfy the test, the assert failed in the opposite way.
When I commented out the test, the test failed in an even more drastic
way: it failed in uniqueness constraints in the derby database used in
the test.
And the behaviour was completely repeatable, remove this and see this
error. I got the same behaviour inside eclipse as I did when running
with surefire in maven.
So I figured there had to be some bug in my code: some value or array
that was reused somehow, and I spent some time digging into that without
being able to figure it out. As far as I could tell I created new
ArrayLists containing new data objects.
I eventually figured it had to be related to my new
expected-to-be-failing asserts: and when I made them green, the entire
test ran green.
I tought that was weird and google found me nothing, so I thought I'd
ask here: is triggering the wrong assert when having a failing assert,
normal behaviour in pax exam?
Or is it just me? :-)
Here is what happened/happens (I can reproduce this behaviour at will):
Here is my test: https://gist.github.com/steinarb/fbfb78c8b69a61c92d66bde6b9994573
If I change the assert on line 32 to fail, ie.: https://gist.github.com/steinarb/ecdf40e201c85b671e301e9fea5a09e5
(change "jad" in the expected value to be "jod")
then what fails, is the assert on line 24, ie
assertEquals(1, initialAccounts.size());
The failure stack trace looks like this: https://gist.github.com/steinarb/5792ab35596e47cbca8f086a9bcfde2b
If I change the expected value on line 24 from 1 to 2, ie.
assertEquals(2, initialAccounts.size());
then the test fails because it gets 1 when 2 is expected (ie. you can't win! :-) )
https://gist.github.com/steinarb/8b971ee7729bcaeecfdbc2254b8f9caf
If I comment out the first assert, ie. like this:
//assertEquals(2, initialAccounts.size());
then I get an DerbySQLIntegrityConstraintViolationException exception
that has deserialization issues, but is a constraints error in the table
(what I would get if I tried ti insert an account with an existing
username)
https://gist.github.com/steinarb/ce5f845ca7d67754281b1f42f35fa92e
If I continue to comment out asserts further downn in the test I
continue to get DerbySQLIntegrityConstraintViolationException
exceptions.
But if I change all asserts so that they are green, then everything runs
normal.
Weird!
The project with the karaf pax exam integration test, is here:
https://github.com/steinarb/liquibase-karaf-feature
The pax exam test is here:
https://github.com/steinarb/liquibase-karaf-feature/blob/master/liquibase-integration-test/karaf.liquibase.tests/src/test/java/no/priv/bang/karaf/liquibase/tests/LiquibaseKarafFeatureIntegrationTest.java
openjdk-17-jdk:amd64 17.0.6+10-1~deb11u1 (ie. java 17)
karaf 4.4.3
pax-exam 4.13.5
eclipse 2023-03 (4.27.0)
What I usually do when creating JUnit tests is to run in a
red-green-red-green... rythm, the way Martin Fowler taught me.
I.e. I create the test first to be failing and then I make the test
green, create a new failure situation, fix the failure to make the test
green and so on.
When doing this on a pax exam test I saw some weird behaviour: the first
assert in the test was failing, and when I changed the expected value to
satisfy the test, the assert failed in the opposite way.
When I commented out the test, the test failed in an even more drastic
way: it failed in uniqueness constraints in the derby database used in
the test.
And the behaviour was completely repeatable, remove this and see this
error. I got the same behaviour inside eclipse as I did when running
with surefire in maven.
So I figured there had to be some bug in my code: some value or array
that was reused somehow, and I spent some time digging into that without
being able to figure it out. As far as I could tell I created new
ArrayLists containing new data objects.
I eventually figured it had to be related to my new
expected-to-be-failing asserts: and when I made them green, the entire
test ran green.
I tought that was weird and google found me nothing, so I thought I'd
ask here: is triggering the wrong assert when having a failing assert,
normal behaviour in pax exam?
Or is it just me? :-)
Here is what happened/happens (I can reproduce this behaviour at will):
Here is my test: https://gist.github.com/steinarb/fbfb78c8b69a61c92d66bde6b9994573
If I change the assert on line 32 to fail, ie.: https://gist.github.com/steinarb/ecdf40e201c85b671e301e9fea5a09e5
(change "jad" in the expected value to be "jod")
then what fails, is the assert on line 24, ie
assertEquals(1, initialAccounts.size());
The failure stack trace looks like this: https://gist.github.com/steinarb/5792ab35596e47cbca8f086a9bcfde2b
If I change the expected value on line 24 from 1 to 2, ie.
assertEquals(2, initialAccounts.size());
then the test fails because it gets 1 when 2 is expected (ie. you can't win! :-) )
https://gist.github.com/steinarb/8b971ee7729bcaeecfdbc2254b8f9caf
If I comment out the first assert, ie. like this:
//assertEquals(2, initialAccounts.size());
then I get an DerbySQLIntegrityConstraintViolationException exception
that has deserialization issues, but is a constraints error in the table
(what I would get if I tried ti insert an account with an existing
username)
https://gist.github.com/steinarb/ce5f845ca7d67754281b1f42f35fa92e
If I continue to comment out asserts further downn in the test I
continue to get DerbySQLIntegrityConstraintViolationException
exceptions.
But if I change all asserts so that they are green, then everything runs
normal.
Weird!
The project with the karaf pax exam integration test, is here:
https://github.com/steinarb/liquibase-karaf-feature
The pax exam test is here:
https://github.com/steinarb/liquibase-karaf-feature/blob/master/liquibase-integration-test/karaf.liquibase.tests/src/test/java/no/priv/bang/karaf/liquibase/tests/LiquibaseKarafFeatureIntegrationTest.java
Grzegorz Grzybek
Jun 7, 2023, 3:43:02 AM6/7/23
to op...@googlegroups.com
Hello
I'd like to help, but seeing this in your shared test:
final MavenArtifactUrlReference sampleappFeatureRepo = maven()
.groupId("no.priv.bang.karaf")
.artifactId("karaf.liquibase.sample.datasource.receiver")
doesn't help - this is your private artifact and you'd have to share entire project and not a @Test method.
--
--
------------------
OPS4J - http://www.ops4j.org - op...@googlegroups.com
---
You received this message because you are subscribed to the Google Groups "OPS4J" group.
To unsubscribe from this group and stop receiving emails from it, send an email to ops4j+un...@googlegroups.com.
To view this discussion on the web visit https://groups.google.com/d/msgid/ops4j/87mt1fjhiz.fsf%40dod.no.
Steinar Bang
Jun 7, 2023, 5:34:05 PM6/7/23
to op...@googlegroups.com
>>>>> Grzegorz Grzybek <gr.grzybek-Re5JQ...@public.gmane.org>:
> Hello
> I'd like to help, but seeing this in your shared test:
> final MavenArtifactUrlReference sampleappFeatureRepo = maven()
>> .groupId("no.priv.bang.karaf")
>> .artifactId("karaf.liquibase.sample.datasource.receiver")
>>
> doesn't help - this is your private artifact and you'd have to share entire
> project and not a @Test method.
Ah, sorry! It is the integration test for my liquibase karaf feature
https://github.com/steinarb/liquibase-karaf-feature
Liquibase is a database migration tool, similar to flyway.
The integration test is here:
https://github.com/steinarb/liquibase-karaf-feature/tree/master/liquibase-integration-test
The test consists of three OSGi bundles and a karaf pax exam test that
loads the feature, and tries to use the database enough to prove that
the loaded feature actually works and can be used to create a database
schema.
The integration test used to be just loading the feature, but I found
out a while back that that was not enough to signal if the new karaf
release I was creating was actually working in an OSGi context: create a
row in a database and reading the results back.
So now the test consists of three bundles:
karaf.liquibase.sample
Contains a pax jdbc PreHook DS component
karaf.liquibase.sample.services
The OSGi service used in the pax exam test to add data to the database
and read data back from the database
karaf.liquibase.sample.datasource.receiver
Contains a DS component exposing the OSGi service used in the karaf
pax exam test, with feature dependencies to both of the above bundles'
attached feature repositories
karaf.liquibase.tests
The karaf pax exam test where the asserts are weird
> I completely support red-green-red-green-... cycle. But I'm pretty sure
> Martin Fowler didn't have integration tests in mind. It was about unit
> tests.
Oh I agree, but it looked like a JUnit test, and when the behaviour got
weird I started looking for problems in the code being executed by the
test (and this code is just dummy code, since what I'm trying to do is
verify that the liquibase loaded by the karaf feature is actually able
to create a database schema).
> You seem to be testing everything including verification of database
> content. Getting assertion exceptions in your tests code _may_ lead to
> transaction rollback (I have no idea if this is true - I'd have to see
> your entire test setup).
Maybe...? There shouldn't be any open transactions across the asserts or
even across the methods called between the asserts.
I wrap all of my read and write interactions with JDBC in a
try-with-resource for a JDBC Connection instance.
> I can't help with any particular issue here - I recommend you to check
> Karaf's own Pax Exam integration tests:
> https://github.com/apache/karaf/tree/main/itests/test - see how the tests
> are structured.
> I also can suggest Pax Web tests where I tried very hard to put as many
> comments/explanations I could:
> https://github.com/ops4j/org.ops4j.pax.web/tree/main/pax-web-itest/pax-web-itest-karaf
Thanks!
FWIW the pax exam test works fine for me, when all of the asserts are green.
It's just the
> Hello
> I'd like to help, but seeing this in your shared test:
> final MavenArtifactUrlReference sampleappFeatureRepo = maven()
>> .groupId("no.priv.bang.karaf")
>> .artifactId("karaf.liquibase.sample.datasource.receiver")
>>
> doesn't help - this is your private artifact and you'd have to share entire
> project and not a @Test method.
https://github.com/steinarb/liquibase-karaf-feature
Liquibase is a database migration tool, similar to flyway.
The integration test is here:
https://github.com/steinarb/liquibase-karaf-feature/tree/master/liquibase-integration-test
The test consists of three OSGi bundles and a karaf pax exam test that
loads the feature, and tries to use the database enough to prove that
the loaded feature actually works and can be used to create a database
schema.
The integration test used to be just loading the feature, but I found
out a while back that that was not enough to signal if the new karaf
release I was creating was actually working in an OSGi context: create a
row in a database and reading the results back.
So now the test consists of three bundles:
karaf.liquibase.sample
Contains a pax jdbc PreHook DS component
karaf.liquibase.sample.services
The OSGi service used in the pax exam test to add data to the database
and read data back from the database
karaf.liquibase.sample.datasource.receiver
Contains a DS component exposing the OSGi service used in the karaf
pax exam test, with feature dependencies to both of the above bundles'
attached feature repositories
karaf.liquibase.tests
The karaf pax exam test where the asserts are weird
> I completely support red-green-red-green-... cycle. But I'm pretty sure
> Martin Fowler didn't have integration tests in mind. It was about unit
> tests.
weird I started looking for problems in the code being executed by the
test (and this code is just dummy code, since what I'm trying to do is
verify that the liquibase loaded by the karaf feature is actually able
to create a database schema).
> You seem to be testing everything including verification of database
> content. Getting assertion exceptions in your tests code _may_ lead to
> transaction rollback (I have no idea if this is true - I'd have to see
> your entire test setup).
even across the methods called between the asserts.
I wrap all of my read and write interactions with JDBC in a
try-with-resource for a JDBC Connection instance.
> I can't help with any particular issue here - I recommend you to check
> Karaf's own Pax Exam integration tests:
> https://github.com/apache/karaf/tree/main/itests/test - see how the tests
> are structured.
> I also can suggest Pax Web tests where I tried very hard to put as many
> comments/explanations I could:
> https://github.com/ops4j/org.ops4j.pax.web/tree/main/pax-web-itest/pax-web-itest-karaf
FWIW the pax exam test works fine for me, when all of the asserts are green.
It's just the
Steinar Bang
Jun 11, 2023, 9:51:00 AM6/11/23
to op...@googlegroups.com
>>>>> Steinar Bang <sb-1rLz...@public.gmane.org>:
assert fails...?
That would explain both the non-causal behaviour of breaking a late
assert making an earlier assert fail, and the database constraints
failure caused by trying to add the same username twice (see other,
related thread).
I think maybe, if I make each run of the integration test have an unique
database name, then both the weird non-causal asserts, and the database
constraint failures will go away, and then, maybe, the correct failing
assert will be highlighted.
>> You seem to be testing everything including verification of database
>> content. Getting assertion exceptions in your tests code _may_ lead to
>> transaction rollback (I have no idea if this is true - I'd have to see
>> your entire test setup).
> Maybe...? There shouldn't be any open transactions across the asserts or
> even across the methods called between the asserts.
> I wrap all of my read and write interactions with JDBC in a
> try-with-resource for a JDBC Connection instance.
I think it is related to the test somehow being run twice, when an
>> content. Getting assertion exceptions in your tests code _may_ lead to
>> transaction rollback (I have no idea if this is true - I'd have to see
>> your entire test setup).
> Maybe...? There shouldn't be any open transactions across the asserts or
> even across the methods called between the asserts.
> I wrap all of my read and write interactions with JDBC in a
> try-with-resource for a JDBC Connection instance.
assert fails...?
That would explain both the non-causal behaviour of breaking a late
assert making an earlier assert fail, and the database constraints
failure caused by trying to add the same username twice (see other,
related thread).
I think maybe, if I make each run of the integration test have an unique
database name, then both the weird non-causal asserts, and the database
constraint failures will go away, and then, maybe, the correct failing
assert will be highlighted.
Grzegorz Grzybek
Jun 16, 2023, 2:11:10 AM6/16/23
to op...@googlegroups.com
Hello
Sorry, but I didn't have time to check/run your integration tests.
You've mentioned that the test may be run twice - that's possible depending on the configuration of maven-surefire/failsafe-plugin. I don't know. Usually in such cases I turn on quite detailed logging, so I can see how all the threads interact. For example in Pax Web I use this logging configuration: https://github.com/ops4j/org.ops4j.pax.web/blob/web-8.0.20/pax-web-itest/pax-web-itest-karaf/src/test/resources/log4j2-test.properties#L38
appender.file.layout.pattern = %d{HH:mm:ss.SSS} [%thread] %-5level (%F:%L) %logger - %msg%n
The most important part is to ensure you have full thread name (%thread), so you can see how the threads interact. I've detected many deadlocks and thread synchronization problems in last years simply by looking at the logs.
If the green tests are fine, you're half way to success ;)
regards
Grzegorz Grzybek
--
--
------------------
OPS4J - http://www.ops4j.org - op...@googlegroups.com
---
You received this message because you are subscribed to the Google Groups "OPS4J" group.
To unsubscribe from this group and stop receiving emails from it, send an email to ops4j+un...@googlegroups.com.
To view this discussion on the web visit https://groups.google.com/d/msgid/ops4j/87o7lmgla7.fsf%40dod.no.
Steinar Bang
Jun 24, 2023, 7:48:37 AM6/24/23
to op...@googlegroups.com
>>>>> Grzegorz Grzybek <gr.grzybek-Re5JQ...@public.gmane.org>:
> Hello
> Sorry, but I didn't have time to check/run your integration tests.
> You've mentioned that the test may be run twice - that's possible depending
> on the configuration of maven-surefire/failsafe-plugin. I don't know.
> Usually in such cases I turn on quite detailed logging, so I can see how
> all the threads interact. For example in Pax Web I use this logging
> configuration:
> https://github.com/ops4j/org.ops4j.pax.web/blob/web-8.0.20/pax-web-itest/pax-web-itest-karaf/src/test/resources/log4j2-test.properties#L38
> appender.file.layout.pattern = %d{HH:mm:ss.SSS} [%thread] %-5level (%F:%L)
> %logger - %msg%n
Thanks!
Where does the log affected by this config end up?
I assume it isn't the karaf.log of the started karaf instance, and it
doesn't seem to affect the console log format?
> The most important part is to ensure you have full thread name (%thread),
> so you can see how the threads interact. I've detected many deadlocks and
> thread synchronization problems in last years simply by looking at the logs.
> If the green tests are fine, you're half way to success ;)
True. :-)
> Hello
> Sorry, but I didn't have time to check/run your integration tests.
> You've mentioned that the test may be run twice - that's possible depending
> on the configuration of maven-surefire/failsafe-plugin. I don't know.
> Usually in such cases I turn on quite detailed logging, so I can see how
> all the threads interact. For example in Pax Web I use this logging
> configuration:
> https://github.com/ops4j/org.ops4j.pax.web/blob/web-8.0.20/pax-web-itest/pax-web-itest-karaf/src/test/resources/log4j2-test.properties#L38
> appender.file.layout.pattern = %d{HH:mm:ss.SSS} [%thread] %-5level (%F:%L)
> %logger - %msg%n
Where does the log affected by this config end up?
I assume it isn't the karaf.log of the started karaf instance, and it
doesn't seem to affect the console log format?
> The most important part is to ensure you have full thread name (%thread),
> so you can see how the threads interact. I've detected many deadlocks and
> thread synchronization problems in last years simply by looking at the logs.
> If the green tests are fine, you're half way to success ;)
Grzegorz Grzybek
Jun 26, 2023, 6:35:32 AM6/26/23
to op...@googlegroups.com
Hello
sob., 24 cze 2023 o 13:48 Steinar Bang <s...@dod.no> napisał(a):
>>>>> Grzegorz Grzybek <gr.grzybek-Re5JQ...@public.gmane.org>:
> Hello
> Sorry, but I didn't have time to check/run your integration tests.
> You've mentioned that the test may be run twice - that's possible depending
> on the configuration of maven-surefire/failsafe-plugin. I don't know.
> Usually in such cases I turn on quite detailed logging, so I can see how
> all the threads interact. For example in Pax Web I use this logging
> configuration:
> https://github.com/ops4j/org.ops4j.pax.web/blob/web-8.0.20/pax-web-itest/pax-web-itest-karaf/src/test/resources/log4j2-test.properties#L38
> appender.file.layout.pattern = %d{HH:mm:ss.SSS} [%thread] %-5level (%F:%L)
> %logger - %msg%n
Thanks!
Where does the log affected by this config end up?
It should be a test log from Pax Exam itself in target directory of Maven module: target/logs/pax-exam-test.log
regards
Grzegorz Grzybek
I assume it isn't the karaf.log of the started karaf instance, and it
doesn't seem to affect the console log format?
> The most important part is to ensure you have full thread name (%thread),
> so you can see how the threads interact. I've detected many deadlocks and
> thread synchronization problems in last years simply by looking at the logs.
> If the green tests are fine, you're half way to success ;)
True. :-)
--
--
------------------
OPS4J - http://www.ops4j.org - op...@googlegroups.com
---
You received this message because you are subscribed to the Google Groups "OPS4J" group.
To unsubscribe from this group and stop receiving emails from it, send an email to ops4j+un...@googlegroups.com.
To view this discussion on the web visit https://groups.google.com/d/msgid/ops4j/87edm1ulm7.fsf%40dod.no.
Steinar Bang
Jun 27, 2023, 1:29:39 PM6/27/23
to op...@googlegroups.com
>>>>> Grzegorz Grzybek <gr.grzybek-Re5JQ...@public.gmane.org>:
I did the following:
1. Added the log4j2-test.properties file to the /src/test/resources
directory of the integration test
https://github.com/steinarb/scratch/tree/liquibase-karaf-feature/add-debug-logging
https://github.com/steinarb/scratch/commit/27cdec12366fd7f6fd4cef481b9299756ff74015
2, Ran "mvn clean install" on the project's top level
Unfortunately the target directory of the integration test doesn't seem
to have a logs subdirectory:
/home/sb/workspaces/liquibase-karaf-feature/liquibase-integration-test/karaf.liquibase.tests/target:
total used in directory 48 available 371.1 GiB
drwxr-xr-x 10 sb sb 4096 Jun 27 19:17 .
drwxr-xr-x 5 sb sb 4096 Jun 27 19:16 ..
drwxr-xr-x 3 sb sb 4096 Jun 27 19:16 classes
drwxr-xr-x 3 sb sb 4096 Jun 27 19:16 exam
drwxr-xr-x 3 sb sb 4096 Jun 27 19:16 generated-test-sources
drwxr-xr-x 2 sb sb 4096 Jun 27 19:17 javadoc-bundle-options
-rw-r--r-- 1 sb sb 5236 Jun 27 19:17 karaf.liquibase.tests-4.19.1-SNAPSHOT.jar
drwxr-xr-x 2 sb sb 4096 Jun 27 19:17 maven-archiver
drwxr-xr-x 3 sb sb 4096 Jun 27 19:16 maven-status
drwxr-xr-x 2 sb sb 4096 Jun 27 19:16 surefire-reports
drwxr-xr-x 4 sb sb 4096 Jun 27 19:16 test-classes
Thanks!
- Steinar
>> Where does the log affected by this config end up?
> It should be a test log from Pax Exam itself in target directory of Maven
> module: target/logs/pax-exam-test.log
I wasn't able to make it work, unfortunately.
> It should be a test log from Pax Exam itself in target directory of Maven
> module: target/logs/pax-exam-test.log
I did the following:
1. Added the log4j2-test.properties file to the /src/test/resources
directory of the integration test
https://github.com/steinarb/scratch/tree/liquibase-karaf-feature/add-debug-logging
https://github.com/steinarb/scratch/commit/27cdec12366fd7f6fd4cef481b9299756ff74015
2, Ran "mvn clean install" on the project's top level
Unfortunately the target directory of the integration test doesn't seem
to have a logs subdirectory:
/home/sb/workspaces/liquibase-karaf-feature/liquibase-integration-test/karaf.liquibase.tests/target:
total used in directory 48 available 371.1 GiB
drwxr-xr-x 10 sb sb 4096 Jun 27 19:17 .
drwxr-xr-x 5 sb sb 4096 Jun 27 19:16 ..
drwxr-xr-x 3 sb sb 4096 Jun 27 19:16 classes
drwxr-xr-x 3 sb sb 4096 Jun 27 19:16 exam
drwxr-xr-x 3 sb sb 4096 Jun 27 19:16 generated-test-sources
drwxr-xr-x 2 sb sb 4096 Jun 27 19:17 javadoc-bundle-options
-rw-r--r-- 1 sb sb 5236 Jun 27 19:17 karaf.liquibase.tests-4.19.1-SNAPSHOT.jar
drwxr-xr-x 2 sb sb 4096 Jun 27 19:17 maven-archiver
drwxr-xr-x 3 sb sb 4096 Jun 27 19:16 maven-status
drwxr-xr-x 2 sb sb 4096 Jun 27 19:16 surefire-reports
drwxr-xr-x 4 sb sb 4096 Jun 27 19:16 test-classes
Thanks!
- Steinar
Reply all
Reply to author
Forward
0 new messages