junit-team / junit5

✅ The 5th major version of the programmer-friendly testing framework for Java and the JVM
https://junit.org
Other
6.35k stars 1.48k forks source link

Describe mismatches found by assertLinesMatch #2233

Closed tcfurrer closed 4 years ago

tcfurrer commented 4 years ago

Currently, in AssertLinesMatch on main, I see:

    private final static int MAX_SNIPPET_LENGTH = 21;
    private final static int MAX_LINES_IN_FAILURE_MESSAGE = 42;

Please create some way to allow the user of JUnit 5 to configure these parameters, with a value of zero meaning "unlimited". The usefulness of assertLinesMatch degrades when the snippets are too short to show the problem that needs to debugged, and when the relevant lines are omitted.

The numbers 21 and 42 are certainly not "one size fits all" parameters.

Recent releases of IntellJ IDEA have a really nice feature parses the output of assertLinesMatch fails and shows the results in a graphical diff window. The omitted lines make that feature far less valuable than it could be as well.

I think a static knob would be fine. I see no need for these to be changed dynamically during test suite execution.

How about just a simple system property for each of those two parameters?

Thanks!

sbrannen commented 4 years ago

Tentatively slated for 5.7 M1 for team discussion

sormuras commented 4 years ago

Recent releases of IntellJ IDEA have a really nice feature parses the output of assertLinesMatch fails and shows the results in a graphical diff window. The omitted lines make that feature far less valuable than it could be as well.

Can you show me screenshot or link to one of that feature?

On non-matching lines errors, we decided to throw the same assertion error as if two strings didn't match. That leads in all versions of IDEA (since 2018 at least) to a clickable <Click to see difference> in the run log. See this screen taken with Build #IC-201.6668.60, built on April 1, 2020:

image

tcfurrer commented 4 years ago

In this example:

    @Test
    void assertLinesMatchIssue2233Example1() {
        List<String> actualLines = new ArrayList<>();
        for (int i=0; i<42; ++i) actualLines.add("a line of text "+i);
        List<String> expectedLines = List.copyOf(actualLines);
        actualLines.add("a mismatching line that will be invisible in assertion failure message");
        assertLinesMatch(expectedLines, actualLines);
    }

the diff windows looks like: (as you can see, this isn't very useful for debugging the failure) image

In this example: (I should probably file a separate ticket on this?)

    @Test
    void assertLinesMatchIssue2233Example2() {
        List<String> actualLines = new ArrayList<>();
        for (int i=0; i<43; ++i) actualLines.add("a line of text "+i);
        List<String> expectedLines = List.copyOf(actualLines);
        actualLines.set(42, "a mismatching line that will be invisible in assertion failure message");
        assertLinesMatch(expectedLines, actualLines);
    }

the output is bad, and the IDEA "click to see difference" does not appear.

The output looks like: (notice the Object.toString output, which I believe is not intended?)

expected line #43:`a line of text 42` doesn't match ==> expected: java.lang.String@27381520<
a line of text 0
a line of text 1
a line of text 2
a line of text 3
a line of text 4
a line of text 5
a line of text 6
a line of text 7
a line of text 8
a line of text 9
a line of text 10
a line of text 11
a line of text 12
a line of text 13
a line of text 14
a line of text 15
a line of text 16
a line of text 17
a line of text 18
a line of text 19
a line of text 20
a line of text 21
a line of text 22
a line of text 23
a line of text 24
a line of text 25
a line of text 26
a line of text 27
a line of text 28
a line of text 29
a line of text 30
a line of text 31
a line of text 32
a line of text 33
a line of text 34
a line of text 35
a line of text 36
a line of text 37
a line of text 38
a line of text 39
a line of text 40
a line of text 41
[omitted 1 line(s)]
> but was: java.lang.String@43798055<
a line of text 0
a line of text 1
a line of text 2
a line of text 3
a line of text 4
a line of text 5
a line of text 6
a line of text 7
a line of text 8
a line of text 9
a line of text 10
a line of text 11
a line of text 12
a line of text 13
a line of text 14
a line of text 15
a line of text 16
a line of text 17
a line of text 18
a line of text 19
a line of text 20
a line of text 21
a line of text 22
a line of text 23
a line of text 24
a line of text 25
a line of text 26
a line of text 27
a line of text 28
a line of text 29
a line of text 30
a line of text 31
a line of text 32
a line of text 33
a line of text 34
a line of text 35
a line of text 36
a line of text 37
a line of text 38
a line of text 39
a line of text 40
a line of text 41
[omitted 1 line(s)]
>
sormuras commented 4 years ago

The printout of all compared lines is anew to me. And why doesn't that happen with my initial example?

Nevertheless, the "Comparison Failure" window still shows the mismatch: image

tcfurrer commented 4 years ago

I'm guessing the differences in the behavior I'm getting and the behavior you're getting could be due to differences in tool version(s).

I'm using OpenJDK 12, Gradle 6.3, JUnit 5.6.0, and IDEA 2020.1 beta 2 (build #IC-201.6668.13 on March 24, 2020).

sormuras commented 4 years ago

Are you running tests via delegation to Gradle?

tcfurrer commented 4 years ago

Yes

image

sormuras commented 4 years ago

Can you please let IDEA take over and run again? Seems to be a Gradle Test Runner thingy.

tcfurrer commented 4 years ago

In that case... sounds like I should file a ticket against Gradle on this?

I always have to use delegation to Gradle, because my project's build environment is very complex and heavily customized. The behavior with the built-in IDEA test runner isn't be useful to me.

sormuras commented 4 years ago

Let's wait what @marcphilipp says. ;-)

tcfurrer commented 4 years ago

Of course, my original request here would still stand... because when not using the IDE, the omission of lines in the raw text output is still an issue that would be good to improve upon. Because for test failures in continuous integration runs, we only get the text feedback.

marcphilipp commented 4 years ago

In that case... sounds like I should file a ticket against Gradle on this?

Please do. I think when running this through IDEA directly, they call AssertionFailedError.getExpected() and AssertionFailedError.getActual() instead of parsing the message but Gradle does not preserve these when transferring the exception to the build VM and subsequently reports it to IDEA.

tcfurrer commented 4 years ago

Ok, so as requested, I've filed a ticket against Gradle ( https://github.com/gradle/gradle/issues/12764 ), but can we continue here with discussion about providing control over the omission of lines in raw text output outside IDE? Thanks...

marcphilipp commented 4 years ago

Team decision: Investigate a diff-based solution.

sormuras commented 4 years ago

Initial results using diff-match-patch and other diff implementations on the expected and actual list of lines are not as promising as hoped. The staged matching approach of assertLinesMatch with its mini DSL (E = equals, M = matches, F = fast-forward, X = no match) leads to possibly many false positives.

What about this line-by-line comparison summary?

image

Expected | Actual
       1 M 1
    2..5 E 2..5
       6 X 6
   7..10 E 7..10
      11 F 11..16
      12 M 17

This table ...

Applied to the summary above, the table could read:

   Result        |Expected Line              | Actual Line
-----------------|---------------------------|--------------------------|
    1 M 1        |P Bach.java .+ initialized |P Bach.java 11.0-ea in[...]
 2..5 E 2..5     // 4 line pair(s) are equal
    6 X 6        // Mismatch!

Mismatch details of "6 X 6"
  Expected: "P    * Thread.sleep(1000)"
    Actual: "P    * Thread.sleep(10)"

7..10 E 7..10    // 4 line pair(s) are equal
   11 F 11..16   // Fast-Forward marker `>> OVERVIEW >>` ate 6 actual line(s)
   12 M 17       |P Execution of 3 tasks[...]|P Execution of 3 tasks[...]
sormuras commented 4 years ago

Applied to your example, the table coud read:

 1..42 E 1..42   // 42 line pair(s) are equal
    43 X 43      | Mismatch!

Mismatch details of "43 X 43"
  Expected: "a line of text 42"
    Actual: "a mismatching line that will be invisible in assertion failure message"
tcfurrer commented 4 years ago

That output you showed for my example looks great to me.

I honestly haven't put a ton of thought into how I would design the diff algorithm and the output format for this. And yes, given existing features like fast-forwarding, it's not surprising to see from your work so far that getting the general case right here is an interesting challenge.

The one requirement which seems obvious to me is just that some reasonable number of mismatching lines should always be shown... even if they are buried deep within large amounts of output. That's the bread and butter of showing helpful messages for an assertion like this. And your examples meet that requirement, so I'm happy to see some progress. Nice work!

marcphilipp commented 4 years ago

Team decision: Include a mismatch description for each mismatch that shows the line number of the expected and actual lines along the failed assertion message, e.g.

Mismatch details of "43 X 43"
  Expected: "a line of text 42"
    Actual: "a mismatching line that will be invisible in assertion failure message"
sormuras commented 4 years ago

Current exception messages read as follows. Overlayed by the "Comparison Failure" window rendered by IDEA 2020.2.

Example 1

image

Example 2

image

sormuras commented 4 years ago

I did not touch the MAX_SNIPPET_LENGTH = 21 constant, yet.

I think, the current changes address both given examples in a better manner. All other failure messages describe structural error cases, like length of lists, illegal fast-forward markers, etc. Here, a truncated line is a good-enough extra hint why the assertion method raised an exception.

tcfurrer commented 4 years ago

Sounds good. Even though the solution here differed from my original request, it's better satisfying the needs. Theoretically there may be some future reason to make the constants tunable, but I don't see one right now, given the new behavior.

In summary: I'm excited to see the upcoming release with this enhancement! Thanks again!

sormuras commented 4 years ago

Note

The staged matching logic is still working in a "fail-fast mode": only the first non-mathing line pair is reported. Subsequent lines are not processed.

tcfurrer commented 4 years ago

In case someone finds this issue later and the current solution hasn't gone far enough for their needs, I'll just go ahead and ask here now...

@sormuras: Are there already plans to make additional improvements in this area in the longer term? Specifically to help reduce the need for inefficient onion-peeling in a case where there are several diffs sprinkled throughout a large number of lines? Or should someone file a new issue if that became important?

sormuras commented 4 years ago

Are there already plans to make additional improvements in this area in the longer term?

No. None, yet.

Specifically to help reduce the need for inefficient onion-peeling in a case where there are several diffs sprinkled throughout a large number of lines?

In an earlier stage (around 2017) assertLinesMatch collected all mismatches and presented them in an "en bloc" report at the end. IIRC, that works out if no fast-forward marker was used. If one or more fast-forward markers were in play, the report contained false positive resulting follow-up errors. It made the textual report effectively useless.

For me, the best solution so far, is to open the "Comparison" window of an IDE(A). The expected (possibly DSL-styled) lines on one side, and the actual lines on the other. Here, you already have all lines in sight, without "onion-peeling" through them. The scroll bar, the colored regex matches/mismatches, the line-based relation graphs ... see the screenshot attached to https://github.com/junit-team/junit5/issues/2233#issuecomment-608023094 ... are very hard to render textually in an exception message.

Or should someone file a new issue if that became important?

Yes. A new issue would work best.

tcfurrer commented 4 years ago

Thanks very much @sormuras for that clear summary of the situation as it stands now.

For tests that can be run within an IDE, I agree that the graphical diff is best. But also, having the first mismatching line shown clearly prior to launching that GUI view is very nice too, because sometimes it will be enough on its own, and that will help keep the overall debugging process more efficient.

I think room for future improvement now lies in the long-running tests (which are usually run non-interactively in continuous integration automation). Those are generally not worth re-running in the IDE just to get a graphical diff from the failing assertion. Doing so might require redundant execution of a multi-hour test. So I think it's somewhat likely that someone will eventually create a new issue requesting improvements for this scenario. However, I'm perfectly happy leaving that for another day where the full context and motivations for it become more concrete.