[Prototype] log/logtest: Redesign

[pellared]

I want logtest to be easy to use by people who use:

• testify
• go-cmp
• just the standard library

Fixes #6341

Some reasons behind the changes:

• %+v of Recording looks nice (without taking attribute.Set into acount, but this could be improved separately).
• types are easy to create in tests and easy to compare
• tests does not require any helper library to write tests efficiently, gives more freedom for the users on how they want to assert the records

I was thinking very long about adding options to Equal like WithoutTimestamps. But then the issue is that when you dump the results for the failure message you still have them and it does not help the reader to see what when wrong. The user can also e.g. to remove values from attributes. I checked and this pattern also works very nice with google/go-cmp if someone wants to see the diff in the failure message. Moreover, options like WithoutValue are not fine-grained. E.g. you cannot remove the values only for attributes with given key.

TODO:

• I will check if I can reuse it in Contrib for our bridges

[dmathieu]

This looks very nice.
I think it would make sense to see what changes will be required in one of the bridges?

[dmathieu]

Would it make sense to provide an helper method that tells us what is not equal?

[pellared]

I think if people need it then go-cmp should be used. This is also what the official Go guidelines recommend: https://go.dev/wiki/TestComments#equality-comparison-and-diffs

More in Google Go styleguide: https://google.github.io/styleguide/go/decisions#equality-comparison-and-diffs

I will try it out. At first glance, it may occur that it would be better to provide Equal functions instead of as Equal method because of https://pkg.go.dev/github.com/google/go-cmp/cmp#Equal:

If the values have an Equal method of the form "(T) Equal(T) bool" or "(T) Equal(I) bool" where T is assignable to I, then use the result of x.Equal(y) even if x or y is nil. Otherwise, no such method exists and evaluation proceeds to the next rule.

I quickly tried https://pkg.go.dev/github.com/google/go-cmp/cmp#example-Option-AvoidEqualMethod but it did not work. Maybe, I made some silly mistake. I will look into it probably tomorrow.

[pellared]

it may occur that it would be better to provide Equal functions instead of as Equal method because of https://pkg.go.dev/github.com/google/go-cmp/cmp#Equal

Checked. It would be better to do so. Then this is how go-cmp can be used:

	seq := cmpopts.EquateComparable(context.Background())
	if diff := cmp.Diff(want, got, seq); diff != "" {
		t.Errorf("Recorded records mismatch (-want +got):\n%s", diff)
	}

Example output:

--- FAIL: TestRecorderEmitAndReset (0.00s)
    recorder_test.go:99: Recorded records mismatch (-want +got):
          logtest.Recording{
                {Name: "TestRecorderEmitAndReset"}: {
                        {
                                ... // 5 identical fields
                                SeverityText: "",
                                Body:         s"Hello there",
                                Attributes: []log.KeyValue{
        +                               s"n:1",
                                        s"foo:bar",
                                },
                        },
                },
          }
FAIL
exit status 1
FAIL    go.opentelemetry.io/otel/log/logtest    0.004s

Will do tomorrow.

I plan to make API similar to https://pkg.go.dev/go.opentelemetry.io/otel/sdk/metric/metricdata/metricdatatest#AssertEqual.

func Equal[T Recording | Record](a, b T) bool

[pellared]

Would it make sense to provide an helper method that tells us what is not equal?

We can consider it in future. Adding a Diff function would not be a breaking change.

For now, I think we can simply use go-cmp, testify or even Equal depending on preference.
The API from the current prototype allows using all of 3 libraries in a quite usable way (in my opinion).
Each of these approaches has some pros and cons.

With Equal and standard library approach the biggest issue is that it does not print the diff (it prints everything). Other tools need to be used to check the diff. Ignoring fields means changing the got (personally, I do not find it bad).

func TestRecordingEqualWithStdLib(t *testing.T) {
	got := Recording{
		Scope{Name: t.Name()}: []Record{
			{
				Timestamp: time.Now(),
				Severity:  log.SeverityInfo,
				Body:      log.StringValue("Hello there"),
				Attributes: []log.KeyValue{
					log.String("foo", "bar"),
					log.Int("n", 1),
				},
			},
		},
		Scope{Name: "Empty"}: nil,
	}

	want := Recording{
		Scope{Name: t.Name()}: []Record{
			{
				Severity: log.SeverityInfo,
				Body:     log.StringValue("Hello there"),
				Attributes: []log.KeyValue{
					log.Int("n", 1),
					log.String("foo", "bar"),
				},
			},
		},
		Scope{Name: "Empty"}: []Record{},
	}
	// Ignore Timestamp.
	for _, recs := range got {
		for i, r := range recs {
			r.Timestamp = time.Time{}
			recs[i] = r
		}
	}
	if !Equal(want, got) {
		t.Errorf("Recording mismatch\na:\n%+v\nb:\n%+v", want, got)
	}
}

With testify the biggest issue you cannot force []log.KeyValue to sort slices before comparing (unordered collection equality). This can make the test too much "white-boxed" and can easy break during refactoring. Moreover, empty and nil slices are seen not equal. Ignoring fields means changing the got (personally, I do not find it bad).

func TestRecordingEqualWithTestify(t *testing.T) {
	got := Recording{
		Scope{Name: t.Name()}: []Record{
			{
				Timestamp: time.Now(),
				Severity:  log.SeverityInfo,
				Body:      log.StringValue("Hello there"),
				Attributes: []log.KeyValue{

					log.Int("n", 1),
					log.String("foo", "bar"),
				},
			},
		},
		Scope{Name: "Empty"}: nil,
	}

	want := Recording{
		Scope{Name: t.Name()}: []Record{
			{
				Severity: log.SeverityInfo,
				Body:     log.StringValue("Hello there"),
				Attributes: []log.KeyValue{
					// Attributes order has to be the same.
					log.Int("n", 1),
					log.String("foo", "bar"),
				},
			},
		},
		// Nil and empty slices are different for testify.
		Scope{Name: "Empty"}: nil,
	}
	// Ignore Timestamp.
	for _, recs := range got {
		for i, r := range recs {
			r.Timestamp = time.Time{}
			recs[i] = r
		}
	}
	assert.Equal(t, want, got)
}

With go-cmp the biggest issue is that depending on the test different options have to be passed. It takes some time after you get the right set of options. It is probably the most powerful tool.

func TestEqualRecordingWithGoCmp(t *testing.T) {
	got := Recording{
		Scope{Name: t.Name()}: []Record{
			{
				Timestamp: time.Now(),
				Severity:  log.SeverityInfo,
				Body:      log.StringValue("Hello there"),
				Attributes: []log.KeyValue{
					log.String("foo", "bar"),
					log.Int("n", 1),
				},
			},
		},
		Scope{Name: "Empty"}: nil,
	}

	want := Recording{
		Scope{Name: t.Name()}: []Record{
			{
				Severity: log.SeverityInfo,
				Body:     log.StringValue("Hello there"),
				Attributes: []log.KeyValue{
					log.Int("n", 1),
					log.String("foo", "bar"),
				},
			},
		},
		Scope{Name: "Empty"}: []Record{},
	}
	seq := cmpopts.EquateComparable(context.Background())
	ordattr := cmpopts.SortSlices(func(a, b log.KeyValue) bool { return a.Key < b.Key })
	ignstamp := cmpopts.IgnoreTypes(time.Time{}) // ignore Timestamps
	if diff := cmp.Diff(want, got, seq, ordattr, ignstamp, cmpopts.EquateEmpty()); diff != "" {
		t.Errorf("Recorded records mismatch (-want +got):\n%s", diff)
	}
}

Feedback is welcome.

Planing to try it out against bridges in Contrib in upcoming days.

[dashpole]

As long as I can see diffs when tests fail, i'm happy.

I've liked working with go's CMP library when i've used it. It is definitely very powerful, but does take a while to figure out which options to pass. It would be good to document recommended options for most instrumentation tests. I suspect they will generally be the same for most instrumentation libraries

[pellared]

It would be good to document recommended options for most instrumentation tests. I suspect they will generally be the same for most instrumentation libraries

I feel the same. I can even add it as a "testable example".

[codecov]

Codecov Report

All modified and coverable lines are covered by tests ✅

Project coverage is 81.9%. Comparing base (597e1d7) to head (c4ac836).

Additional details and impacted files

@@          Coverage Diff          @@
##            main   #6342   +/-   ##
=====================================
  Coverage   81.8%   81.9%           
=====================================
  Files        283     281    -2     
  Lines      24900   24917   +17     
=====================================
+ Hits       20387   20410   +23     
+ Misses      4109    4103    -6     
  Partials     404     404           

see 3 files with indirect coverage changes