Open ascopes opened 1 year ago
ascopes
commented
1 year ago Since I am not sure of the conditions causing this issue, it is hard to make a minimal working reproduction. However, I seem to be able to reproduce this by in my project. Should be able to trigger it with:
$ git clone git@github.com:ascopes/java-compiler-testing
$ cd java-compiler-testing
$ git checkout 511f1e87d4ff6316ac8330bb800e16c707d83953
$ ./mvnw clean test -am -e -pl java-compiler-testing -T4
fabriciorby
commented
1 year ago Since I am not sure of the conditions causing this issue, it is hard to make a minimal working reproduction. However, I seem to be able to reproduce this by in my project. Should be able to trigger it with:
$ git clone git@github.com:ascopes/java-compiler-testing $ cd java-compiler-testing $ git checkout 511f1e87d4ff6316ac8330bb800e16c707d83953 $ ./mvnw clean test -am -e -pl java-compiler-testing -T4
I followed these steps and I was not able to reproduce :/
Not so long ago I've opened an issue in the SUREFIRE Jira and for some reason it looks like that the <exclude> tag can change the behavior of how the tests are printed. (https://issues.apache.org/jira/browse/SUREFIRE-2111?page=com.atlassian.jira.plugin.system.issuetabpanels%3Acomment-tabpanel&focusedCommentId=17652515#comment-17652515)
Could you do a favor, please? Could you try to run the same test, but without the <exclude> and see what happens?
ascopes
commented
1 year ago The first 15 or so times I tried this tonight, it seems to have not had the issue. I spotted one run after this that did have it and it would appear to be to do with the ordering of tests.
Looks like passing -Dsurefire.runOrder.random.seed=718860759208 to the Maven invocation makes this occur each time (might be a red herring, but one to try perhaps?)
Just about to try without exclude.
ascopes
commented
1 year ago Without the exclude, it doesn't seem to do it with that above seed. Just rerunning a few runs with random order again as unsetting the <exclude> in my project will cause several integration tests to run which may mess with test ordering. Will also try and attach a debugger to see if I can get any info as to what it is processing when it fails and get back to you.
ascopes
commented
1 year ago Ok, so I attached a debugger and I can see that testResult.getSourceName() is returning io.github.ascopes.jct.tests.unit.compilers.AbstractJctCompilerTest$TargetTests. The getTreeLength is going to return 1 from this, I assume.
The class results list itself only has the one element though:
...so the .get(1) is going to fail there.
I managed to debug this by creating mvnwDebug scripts (./mvnw wrapper:wrapper -DincludeDebug=true), and then running ./mvnwDebug -Dsurefire.runOrder.random.seed=718860759208 -T4 -pl java-compiler-testing -am test on git ref 511f1e87d4ff6316ac8330bb800e16c707d83953 as above.
I attached a remote debugger on port 8000 from IntelliJ once I ran this, and added an exception break point on any IndexOutOfBoundsException getting raised. I then manually added the junit5-tree-reporter plugin to my POM while the debugger was running and instructed IntelliJ to refresh the project dependencies so I could get the source code for the plugin while the debugger stopped on it.
Looks like it definitely might be related to what you suggested. I am guessing this is making the assumption that the outer class runs tests before the inner class or something. The bit I am a bit confused on is that the data in classResults shows a completely different test class to the one in testResult.
Could it be a race condition somewhere perhaps? The call to printTests:111 in TestReportHandler show at least two different test classes in the list of tests being rendered.
get:4959, Collections$SingletonList (java.util)
printClass:162, TreePrinter$TestPrinter (org.apache.maven.plugin.surefire.report)
printTest:96, TreePrinter$TestPrinter (org.apache.maven.plugin.surefire.report)
access$500:85, TreePrinter$TestPrinter (org.apache.maven.plugin.surefire.report)
lambda$printTests$1:82, TreePrinter (org.apache.maven.plugin.surefire.report)
accept:-1, TreePrinter$$Lambda$247/0x000000080145e230 (org.apache.maven.plugin.surefire.report)
accept:183, ForEachOps$ForEachOp$OfRef (java.util.stream)
accept:197, ReferencePipeline$3$1 (java.util.stream)
forEachRemaining:1625, ArrayList$ArrayListSpliterator (java.util)
copyInto:509, AbstractPipeline (java.util.stream)
wrapAndCopyInto:499, AbstractPipeline (java.util.stream)
evaluateSequential:150, ForEachOps$ForEachOp (java.util.stream)
evaluateSequential:173, ForEachOps$ForEachOp$OfRef (java.util.stream)
evaluate:234, AbstractPipeline (java.util.stream)
forEach:596, ReferencePipeline (java.util.stream)
printTests:82, TreePrinter (org.apache.maven.plugin.surefire.report)
printTests:111, TestReportHandler (org.apache.maven.plugin.surefire.report)
print:44, TestReportHandler (org.apache.maven.plugin.surefire.report)
testSetCompleted:26, ConsoleTreeReporterBase (org.apache.maven.plugin.surefire.report)
testSetCompleted:32, ConsoleTreeReporterUnicode (org.apache.maven.plugin.surefire.report)
testSetCompleted:8, ConsoleTreeReporterBase (org.apache.maven.plugin.surefire.report)
testSetCompleted:213, TestSetRunListener (org.apache.maven.plugin.surefire.report)
handle:147, ForkClient$TestSetCompletedListener (org.apache.maven.plugin.surefire.booterclient.output)
handle:135, ForkClient$TestSetCompletedListener (org.apache.maven.plugin.surefire.booterclient.output)
notifyEvent:233, ForkedProcessEventNotifier (org.apache.maven.plugin.surefire.booterclient.output)
handleEvent:353, ForkClient (org.apache.maven.plugin.surefire.booterclient.output)
handleEvent:59, ForkClient (org.apache.maven.plugin.surefire.booterclient.output)
run:96, ThreadedStreamConsumer$Pumper (org.apache.maven.plugin.surefire.booterclient.output)
run:1589, Thread (java.lang)(☝🏻 stacktrace within the IntelliJ debugger)
I'm off to bed for the night now, but if I have time tomorrow and there is any other info you need, I'll try and find it out and let you know.
Thanks for the quick response!
fabriciorby
commented
1 year ago Hey, thanks for all the effort with debugging!
I just discovered this issue with <exclude> 5 days ago, the ticket was raised exactly while I was developing some features in July. So using <exclude> is absolutely untested and will get problems with Parameterized and Nested tests (afaik).
Unfortunately, there's no easy fix and I will need some more time to analyze what can be done. Of course, you're very welcome to help if you want.
ascopes
commented
1 year ago Cool, no worries. I may be able to look at some stuff at the weekend if I have time, so feel free to shout if there is anything in particular.
aukevanleeuwen
commented
6 months ago Could you do a favor, please? Could you try to run the same test, but without the
and see what happens?
FYI: I have this exact same error, but I don't have any <excludes />. I do have <includes /> explicitly though, so maybe that's different?
I'm using this reporter in a maven-failsafe-plugin configuration though, not a surefire one, but I think that plugin code is essentially the same.
aukevanleeuwen
commented
6 months ago Since the earlier referenced JIRA issue mentions something about @Nested classes, I tried a couple of times and I cannot reproduce it if I don't use the @Nested. I can reproduce it if I do use it, so that's a pointer of where it's going wrong.
Adding -Dfailsafe.excludes= or changing that configuration to have <excludes><exclude /></excludes> doesn't help by the way.
So I can reliably reproduce, but can't share the code as it is. I will try to debug it a bit as well.
aukevanleeuwen
commented
6 months ago I can't say I dove into it so much that I really understand everything that happening, but in the end it goes wrong in the following location:
Where treeLength is calculated here upon creation of the TreePrinter here:
Again I didn't dive into it very deeply (don't have the time for that), but I don't understand why you would calculate your own treeLength based on the number of $ characters in the class name. Wouldn't it be roughly the same as just setting treeLength to classResults.size() - 1? Then you should be always safe or am I missing something?
-- twenty minutes later --
I'm probably missing something, there is a bunch more stuff that you do to make nested tests work correctly but apparently there are some assumptions about in what order nested classes are processed, which is not the case in this parallel scenario.
One pointer perhaps that might help you is that in this block of code:
I end up in the else case where it's failing whereas maybe you would have expected it to fall into the if.
--- some more time later ---
I give up for now. I'll leave this as a reference for which paths I have tried to debug, maybe it helps, maybe it doesn't. It seems like in the end there is a hidden assumption somewhere that if you have a @Nested class within another class that top level class will at least be done 'first', but this doesn't seem to be the case. So maybe it does indeed seem related to the JIRA issue mentioned earlier, but the workaround does work for me. In the end I'm running concurrent tests and it seems that JUnit has no issues running the nested class even before it has executed a test in the 'parent' class. Could that be the direction that you need to reproduce this scenario?
I fully realise that this is all open source and the work and I can't really expect you to fix it, but you have a better idea of where it might go wrong in that case. Obviously I'm grateful for the work you have put in, but if you find some time it would be awesome if this could be fixed for the greater community.
aukevanleeuwen
commented
6 months ago Another thing that I've noticed that is odd, is that when using this plugin and having @Disabled tests, those tests are duplicated in the output (?). Again just jotting it down here, because maybe it triggers something with the original author @fabriciorby...
fabriciorby
commented
6 months ago hey @aukevanleeuwen, bedankt voor je hulp.
it's correct, there are many things I needed to just assume that would occur from the surefire part, or that I had to debug surefire in order to do it
oh yes, it's very annoying to debug this code, because it is attached in maven, and you have to debug the maven goal, in my small test suite it was working, but after it got slightly popular I realized there are many edge cases that are all screwed, and some I don't know if it's even possible to be fixed
thanks for spending a considerable time trying to figure it out, I really want to take some time and follow on these bugs
I was also wanting to rewrite it to be parsed in a better Tree data structure, the way it's right now is kind of gross, but the thing is it's been a long time and I also need some time to understand once again how this stuff works :/
but now it's summer time here in the Netherlands, I'll dig into it in some months when the weather gets depressive again
thanks again, it sparkled me some motivation
Just had a look in my Surefire reports output directory and spotted the following:
target/surefire-reports/2022-12-30T14-01-27_616-jvmRun1.dumpstreamTests appear to still be running, though. I don't know how serious this is or whether it is anything to worry about or not.
Other info:
Invocation:
$ ./mvnw clean verify -T8src/test/resources/junit-platform.properties