Gomega Output is Unusable

[jontonsoup]

Hi friends,

Thanks for making this awesome library! I've noticed that when using gstruct on large structs the failure mode is impossible to read.

I am using iterm 2 and this command:

godotenv -f .env.test ginkgo -r --randomizeAllSpecs --randomizeSuites --failOnPending --trace --race $@

Here is the test:

        Expect(result).To(ConsistOf(
            PointTo(MatchFields(IgnoreExtras, Fields{
                "EventCode":         Equal("NSD"),

                "Country":           Equal("USA"),

                "MaxRunners":        Equal(35),
                "ProgramStatus":     Equal("O"),
                "Races": ConsistOf(
                    MatchFields(IgnoreExtras, Fields{
                        "MTP":        Equal(15),
                        "Number": Equal(1),
                        "Status": Equal("OPEN"),
                        "TimeZone":   Equal("PT"),

                    }),
                ),
            })),
        ))
    })

I've attached a picture of output.

Let me know if there is a setting I can adjust!

Thanks!

[ansd]

Hi @jontonsoup,

have you tried to use ElementsMatchers instead of ConsistOf matchers? This provides much better output. ElementsMatcherss fit nicely together with FieldsMatchers, and from what I understand, this is what the author of the gstruct library (@tallclair) originally had in mind when creating the library.

As a side note: I did a spike in https://github.com/ansd/gomega/commit/924d5a9423b878c445dc555e67ac251c22bd8558 trying to provide better formatting while still using the ConsistOf matchers. When using this commit and setting format.UseStringerRepresentation = true, it provides better formatting (e.g. in the sense that \n indeed prints a new line). However, the output, although formatted, is still so huge that it's difficult to understand why the test failed.

[jontonsoup]

@ansd

Thanks for taking a look at this.

The elements matcher seems like a bunch of extra work for our use case. The ConsistOf is doing exactly what we want, just doing a poor job of figuring out the differences. Rspec does a great job of this.

[ansd]

@jontonsoup, thank you for your follow up comment.

I agree that the ConsistOf matcher does a poor job printing the differences of the two collections in the failure case. I therefore created #368.

However, even when #368 is resolved, it won't solve the unformatted output seen in your attached picture. This is because even when Gomega understands the difference of the two collections and knows about the missing and extra elements, it will print you these elements.

In your example, assuming that the outermost ConsistOf matcher fails, it will print you the whole PointTo matcher element:

PointTo(MatchFields(IgnoreExtras, Fields{
    "EventCode":         Equal("NSD"),
    "InternalTrackCode": Equal("ABC"),
    "RaceDate":          Equal("20170620"),
    "TrackCode":         Equal("NAA"),
    "Country":           Equal("USA"),
    "CurrentRace":       Equal(1),
    "MaxRunners":        Equal(35),
    "ProgramStatus":     Equal("O"),
    "Races": ConsistOf(
        MatchFields(IgnoreExtras, Fields{
            "MTP":        Equal(15),
            "RaceNumber": Equal(1),
            "RaceStatus": Equal("OPEN"),
            "RaceBreed":  Equal("TB"),
            "PostTime":   Equal("9:50"),
            "TimeZone":   Equal("PT"),
            "Cycles": ConsistOf(
                MatchFields(IgnoreExtras, Fields{
                    "CycleID": Equal("1"),
                    "PoolTotals": ConsistOf(
                        MatchFields(IgnoreExtras, Fields{
                            "PoolCode": Equal("WN"),
                            "PoolName": Equal("Win"),
                            "PoolAmount": Equal(49),
                        }),
                        MatchFields(IgnoreExtras, Fields{
                            "PoolCode": Equal("PL"),
                            "PoolName": Equal("Place"),
                            "PoolAmount": Equal(55),
                        })),
                })),
        }),
    ),
})),

Currently, printing this matcher element results in the unformatted output seen in your attached picture.

I'm not sure about whether it helps a lot to correctly format the output because the correctly formatted output is still so large that it's difficult to understand why the test failed.

Therefore, for your use case, I would either use the ElementsMatcher instead of the ConsistOf matcher, or if you think that the ElementsMatcher is too much extra work because you need to define the Identifier function, you could try to break the single deeply nested expectation down into multiple expectations?

What do you think?

[jontonsoup]

Thanks for this thoughtful response!

Elements matcher does not work for us, but I see some issues have been addressed in recent updates. We are going to make sure we are running latest and update this ticket to see if things have improved.

Thanks!

[jontonsoup]

I was just reviewing this ticket. Are there any new alternatives or techniques to make the output better?

We have been using this where we can: https://github.com/benmoss/matchers, but it doesn't fully solve our problems

[jieya907]

Hi,

Is it possible to get the failure message better formatted? In this example, there are line breaks printed out as characters rather than actual line breaks.

I'm using gomega v 1.11.0.

Thanks!

[rgalanakis]

It seems like something changed in 1.11 (from 1.10.5): https://github.com/onsi/gomega/compare/v1.10.5...v1.11.0#diff-f582003a7bd35b750f68752f7dcb67e27474a08d1c10137a55bcd01d5cd1f231

I have custom matchers that accept an 'inner' matcher, like:

resp := newRr(`{"a": 1}`)
matcher := &matchers.HaveJsonBodyMatcher{Inner: HaveKeyWithValue("b", BeEquivalentTo(2))}

Before that change, I was able to have an inner matcher and get a message like this:

        Expect(matcher.FailureMessage(resp)).To(HavePrefix(`Expected
    <map[string]interface {} | len:1>: {"a": 1}
to have {key: value} matching
    <map[interface {}]interface {} | len:1>: {"b": {Expected: 2}}`))
    })

After that change, my inner matcher gives me a message like this:

      <string>: Expected
          <map[string]interface {} | len:1>: {"a": <float64>1}
      to have {key: value} matching
          <map[interface {}]interface {} | len:1>: {
              <string>"b": <*matchers.BeEquivalentToMatcher | 0x140002d29c0>{Expected: <int>2},

That is, matcher.Inner.FailureMessage(matcher.actualBodyJson) calls HaveKeyWithValue and that walks the BeEquivalentTo struct, rather than using its error message.

This is a problem for composing matchers, IMO- we never want to see the actual matcher struct walked, we want to see its error message instead (where it's possible/implemented at least, I know in some cases it's not feasible).

Am doing something wrong here, was this a regression, or is this intentional? Is there some way to maintain the old behavior? Since the matchers don't implement any stringer interfaces, that isn't an option.

[onsi]

Hey all,

Output formatting in Gomega could use some love. It's grown in complexity over the years and I imagine a fresh look with some time and effort put in could help improve things. I'd like to carve out time for that but am working on something else at the moment that is taking up most of my time. If there's anyone interested in tackling this let me know...

@rgalanakis I think @blgm made a few changes to the formatting code and might have the most recent context on the changes that led to what you're seeing.

Onsi

[rgalanakis]

Thank you Onsi for the prompt response and this wonderful library. If I get some time in a few months I will see what I can do on the formatting code- I have done significant reflection work in Go so the code is familiar.

[mokiat]

Hi all,

I have been facing this problem a number of times, so I decided to drop a comment as well. Gomega really makes writing tests easy and I am a huge fan, though this problem in particular is pain in the *** 😄

I've had to roll out internally my own wrappers to try and get something decent to output but it doesn't format as well as Gomega would do it and requires a lot of boilerplate code.

My approach has been to add an ability for matchers to describe themselves - currently they can only describe failures in relation to some actual value but cannot describe what they want to verify.

So you can think of extending the matcher interface to something like the following:

type ExtendedMatcher struct {
    types.GomegaMatcher
    format.GomegaStringer
}

An implementation of an Equals wrapper would looke like this:

func Equal(expected any) types.GomegaMatcher {
    return &extendedEqual{
        GomegaMatcher: gomega.Equal(expected),
        description: fmt.Sprintf("equal to %v", format.Object(expected, 0)),
    }
}

type extendedEqual struct {
    types.GomegaMatcher
}

func (e *extendedEqual) GomegaString() string {
    return e.description
}

(NOTE: The code above may have issues - the idea is important)

If you do the same for ConsistsOf and Fields matchers and you can end up with pretty decent output in the end. Probably someone with detailed knowledge in Gomega code could get this to work without any friction and format perfectly (mine has spacing issues).

If no one is willing to work on this and you find this idea a good way forward, I could give it a try (the effort would mostly be to implement GomegaMatcher on existing matchers).

[onsi]

@mokiat this makes sense and jives with some ideas i've been having as well. we need a way for a matcher to describe itself so they compositor matchers (eg SatisfyAll(HaveField("foo", Equal("alpha")), HaveField("bar", ContainElement(BeNumerically("~", 100)))) have a hope of rendering nicely.

This issue has expanded over the years but I do think it's time to address this collection of concerns. I don't want to get into "v2" territory though so i'm hopeful there will be ways to make progress (optional interface methods, a zero-effort migration path to better formatting/diffing).

Perhaps a next step is to write up some design thoughts and circulate them for feedback. I can take a stab at that sometime in the next few weeks.