Return verbose errors why expected method call did not match #97

xmik · 2017-08-03T18:09:43Z

Hi. Thanks for gomock! I just started using it and thought it was not enough verbose when it comes to errors messages.

The benefits

Before this PR, in my tests, I see an error: no matching expected call

GOROOT=/usr/local/go
GOPATH=/ide/work
/usr/local/go/bin/go test -c -i -o /tmp/TestHTTP_makeRequestUsingCustomClient_in_http_client_test_gogo 34-mock-http-client-with-gomock
/tmp/TestHTTP_makeRequestUsingCustomClient_in_http_client_test_gogo -test.v -test.run ^TestHTTP_makeRequestUsingCustomClient$
	controller.go:129: no matching expected call: *myhttp32.MockHTTPClientInterface.Do([0xc420074b00])
	controller.go:174: missing call(s) to *myhttp32.MockHTTPClientInterface.Do(is equal to &{GET some-urla HTTP/1.1 1 1 map[] <nil> <nil> 0 [] false  map[] map[] <nil> map[]   <nil> <nil> <nil> <nil>})
	controller.go:181: aborting test due to missing call(s)

Process finished with exit code 1

after this PR:

GOROOT=/usr/local/go
GOPATH=/ide/work
/usr/local/go/bin/go test -c -i -o /tmp/TestHTTP_makeRequestUsingCustomClient_in_http_client_test_gogo 34-mock-http-client-with-gomock
/tmp/TestHTTP_makeRequestUsingCustomClient_in_http_client_test_gogo -test.v -test.run ^TestHTTP_makeRequestUsingCustomClient$
	controller.go:132: no matching expected call: *myhttp32.MockHTTPClientInterface.Do([0xc42000af00]) /ide/work/src/34-mock-http-client-with-gomock/http_client.go:85
		
		The expected argument of index: 0 of this call: /ide/work/src/34-mock-http-client-with-gomock/http_client_test.go:68 did not match the actual argument.
		Actual argument: is equal to &{GET some-urla HTTP/1.1 1 1 map[] <nil> <nil> 0 [] false  map[] map[] <nil> map[]   <nil> <nil> <nil> <nil>}, expected: &{GET some-url HTTP/1.1 1 1 map[] <nil> <nil> 0 [] false  map[] map[] <nil> map[]   <nil> <nil> <nil> <nil>}
	controller.go:177: missing call(s) to *myhttp32.MockHTTPClientInterface.Do(is equal to &{GET some-urla HTTP/1.1 1 1 map[] <nil> <nil> 0 [] false  map[] map[] <nil> map[]   <nil> <nil> <nil> <nil>}) /ide/work/src/34-mock-http-client-with-gomock/http_client_test.go:68
	controller.go:184: aborting test due to missing call(s)

Process finished with exit code 1

This PR contains

The changes that Show file and line number of call during errors #25 introduces. But it had conflicts in relation to latest master which I fixed.
Changes to FindMatch method. It now also returns an error which explains why there was no call match. I added tests for each error explanation message kind.
I removed the square brackets around call origin (path and line to method invocations), because this way, in Gogland IDE, they are displayed as clickable links.

You may not like

the wording of error messages
the errors messages like :"Actual argument: is equal to 15, expected: 3". It comes from here. It would be prettier if the error message was: "Actual argument: 15, expected: 3". This is because in the method returning this message, the m object is of type Matcher, and it has no public fields, so we can only use its String() method. I don't think it is greatly important.

Please voice any concerns and treat me as unexperienced in Go, as I've just recently started using it.

This commit makes erroneous calls show their origin. Unexpected calls show where they happened. Missing calls and improper expectations show where they were set up in the tests. This information is printed after each error message in square brackets. This commit was originally: ooesili@76f75d8 and a PR for it: golang#25. But there were minor conflicts with master from 2 aug 2017: golang@13f3609, which I fixed.

… as a clickable link

googlebot · 2017-08-03T18:09:47Z

Thanks for your pull request. It looks like this may be your first contribution to a Google open source project. Before we can look at your pull request, you'll need to sign a Contributor License Agreement (CLA).

📝 Please visit https://cla.developers.google.com/ to sign.

Once you've signed, please reply here (e.g. I signed it!) and we'll verify. Thanks.

If you've already signed a CLA, it's possible we don't have your GitHub username or you're using a different email address. Check your existing CLA data and verify that your email is set on your git commits.
If your company signed a CLA, they designated a Point of Contact who decides which employees are authorized to participate. You may need to contact the Point of Contact for your company and ask to be added to the group of authorized contributors. If you don't know who your Point of Contact is, direct the project maintainer to go/cla#troubleshoot.
In order to pass this check, please resolve this problem and have the pull request author add another comment and the bot will run again.

xmik · 2017-08-03T18:19:21Z

I signed it!

googlebot · 2017-08-03T18:19:24Z

CLAs look good, thanks!

xmik · 2017-08-03T19:50:38Z

This PR is also related: #65 and it could be incorporated instead of or in addition to #25.

balshetzer

Thanks for this change. I Agree that it should make failures easier to understand.

balshetzer · 2017-08-05T12:31:20Z

gomock/callset.go

 	}

 	// Search through the unordered set of calls expected on a method on a
 	// receiver.
+	callsErrors := ""
 	for _, call := range calls {
 		// A call should not normally still be here if exhausted,
 		// but it can happen if, for instance, .Times(0) was used.
 		// Pretend the call doesn't match.
 		if call.exhausted() {
 			continue


Here we can add an error explaining that this call didn't match because it was exhausted.

balshetzer · 2017-08-05T12:34:28Z

gomock/controller.go

 		origin := callerInfo(2)
-		ctrl.t.Fatalf("no matching expected call: %T.%v(%v) [%s]", receiver, method, args, origin)
+		ctrl.t.Fatalf("no matching expected call: %T.%v(%v) [%s]\n%s", receiver, method, args, origin, err)


Maybe add a preamble to the explanations? Something like "because".

Also, I've never really liked this error message. I think it's confusing. A more direct message for the user would be something like: "%T.%v(%v) at %s is unexpected because %s" or "Unexpected call %T.%v(%v) at %s because %s". What do you think?

I agree that it is confusing and I prefer your second suggestion. Continuation in the last comment.

balshetzer · 2017-08-05T12:39:11Z

gomock/controller_test.go

+				actualErrMsg := e.log[len(e.log)-1]
+				for _, expectedErrMsg := range expectedErrMsgs {
+					if !strings.Contains(actualErrMsg, expectedErrMsg) {
+						e.t.Errorf("Expected the actual error message:\n'%s'\nto contain expected error message:\n'%s'\n", actualErrMsg, expectedErrMsg)


This is a little verbose. Maybe something shorter? e.g. "Error message: got %q, want .%q."

%q quotes the string.

Yes, sure, changed to:

e.t.Errorf("Error message:\ngot: %q\nwant to contain: %q\n", actualErrMsg, expectedErrMsg)

So that an example failing test would result in output:

controller_test.go:78: Error message: got: "Unexpected call to *gomock_test.Subject.FooMethod([argument extra_argument]) at /ide/work/src/github.com/golang/mock/gomock/controller_test.go:89 because \nExpected call at /ide/work/src/github.com/golang/mock/gomock/controller_test.go:238 has the wrong number of arguments. Got: 2, want: 1" want to contain: "Invalid number of arguments of call"

balshetzer · 2017-08-05T12:42:30Z

gomock/controller_test.go

+	return 0
+}
+
+// Without this method the string representation of a TestStruct object would be e.g. {%!!(MISSING)s(int=123) no message}


Are you sure this comment is correct? This looks like what you get if you pass it into a Sprintf without any formatting directive.

You are right. That comment and function were redundant.

balshetzer · 2017-08-05T13:09:34Z

gomock/controller_test.go

 	})
+}
+
+func TestExpectedMethodCall_CustomStruct(t *testing.T) {


Could you please explain in a comment why we need to test this case?

Added 2 comments. If you find this test not needed, I may as well remove it.

comment to a similar, but easier test: https://github.com/golang/mock/pull/97/files#diff-763a69b80e2e0fb14b7d265a0f71d31eR190

comment to this test: https://github.com/golang/mock/pull/97/files#diff-763a69b80e2e0fb14b7d265a0f71d31eR249

balshetzer · 2017-08-05T13:17:09Z

gomock/call.go

 	if len(args) != len(c.args) {
-		return false
+		return fmt.Errorf("Invalid number of arguments of call: %s. Set: %s, while this call takes: %s",


All the error messages returned are worded as error messages to their respective functions. This makes sense in context but I think it doesn't result in the best final error message to the user. Perhaps, instead, they could be worded for the final use. For example. The errors could say something like "Expected call <call details> <mismatch>". Then, the final message will read something like:
Unexpected call <call details> because:
Expected call <call details> has the wrong number of arguments (<got> vs. <want>)
Expected call <call details> doesn't match argument #<index> (<got> vs <want>)

Let me know what you think.

I like your suggestions very much. I implemented them almost as you said. Only in the case of:

Expected call <call details> doesn't match argument #<index> (<got> vs <want>)

I took the liberty to put got and want in separate lines, because it seems easier to read when the mocked functions take complex arguments. Example from tests of my project which uses Gomock, where an argument is of type: http.Request:

controller.go:132: Unexpected call to *myhttp32.MockHTTPClientInterface.Do([0xc42000af00]) at /ide/work/src/34-mock-http-client-with-gomock/http_client.go:85 because: Expected call at /ide/work/src/34-mock-http-client-with-gomock/http_client_test.go:74 doesn't match the argument at index 0. Got: &{GET some-url HTTP/1.1 1 1 map[] <nil> <nil> 0 [] false map[] map[] <nil> map[] <nil> <nil> <nil> <nil>} Want: is equal to &{GET some-urla HTTP/1.1 1 1 map[] <nil> <nil> 0 [] false map[] map[] <nil> map[] <nil> <nil> <nil> <nil>} controller.go:177: missing call(s) to *myhttp32.MockHTTPClientInterface.Do(is equal to &{GET some-urla HTTP/1.1 1 1 map[] <nil> <nil> 0 [] false map[] map[] <nil> map[] <nil> <nil> <nil> <nil>}) /ide/work/src/34-mock-http-client-with-gomock/http_client_test.go:74 controller.go:184: aborting test due to missing call(s)

I also changed the error message:

No expected method calls for that receiver

to

there are no expected method calls for that receiver

so that it reads better with the Unexpected call <call details> because:

xmik · 2017-08-06T13:09:56Z

@balshetzer, thank you for all the remarks. They are very helpful.

I have now one problem: this line when printed in Gogland, does not result in output containing a clickable link to a particular path and line (the origin argument). While this line does. I will try to solve it. (My last commit did not have any impact on it).

xmik · 2017-08-06T15:15:13Z

So the path and line are not a clickable link if they are in the same line as the path and line to controller.go.

E.g. here /ide/work/src/34-mock-http-client-with-gomock/http_client.go:85 is a link:

controller.go:132: Unexpected call to *myhttp32.MockHTTPClientInterface.Do([0xc42000af00]) at 
		/ide/work/src/34-mock-http-client-with-gomock/http_client.go:85 because:

whereas here it is not:

controller.go:132: Unexpected call to *myhttp32.MockHTTPClientInterface.Do([0xc42000af00]) at /ide/work/src/34-mock-http-client-with-gomock/http_client.go:85 because:

I don't want to dig into this, it is not that crucial.

balshetzer · 2017-08-14T22:02:57Z

@xmik Thanks!

pasztorpisti · 2017-08-15T17:05:35Z

gomock/controller_test.go

@@ -20,6 +20,7 @@ import (
 	"testing"

 	"github.com/golang/mock/gomock"
+	"strings"


Cosmetics: std library imports usually reside in the first "import group"

Ok, @pasztorpisti, I will stick to this advice in the future.

matttproud · 2017-08-22T21:43:27Z

Hi,

I believe this pull request accidentally made the error reporting incur quadratic costs due to the string concatenation in a tight loop routine. I noticed this when running HEAD of GoMock against a large test. According to PProf, the problem was this concatenation: https://github.com/golang/mock/blame/4187d4d04aa043124750c9250259ceafdc5f7380/gomock/callset.go#L68-L78

I have a fix out for review here: #103

xmik added 3 commits August 3, 2017 19:55

Return verbose errors why expected method call did not match

253709b

Do not surround call origin with [] brackets to let Gogland render it…

4187d4d

… as a clickable link

balshetzer reviewed Aug 5, 2017

View reviewed changes

Error messages more clear to read for end user

d35f0d9

balshetzer merged commit 45f67fc into golang:master Aug 14, 2017

pasztorpisti reviewed Aug 15, 2017

View reviewed changes

RJPercival mentioned this pull request Aug 17, 2017

Include stacktrace when no matching expected call #65

Closed

This was referenced Aug 18, 2017

Show file and line number of call during errors #25

Closed

Adding line number of caller #20

Closed

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Return verbose errors why expected method call did not match #97

Return verbose errors why expected method call did not match #97

xmik commented Aug 3, 2017

googlebot commented Aug 3, 2017

xmik commented Aug 3, 2017

googlebot commented Aug 3, 2017

xmik commented Aug 3, 2017

balshetzer left a comment

balshetzer Aug 5, 2017

xmik Aug 6, 2017

balshetzer Aug 5, 2017

xmik Aug 6, 2017

balshetzer Aug 5, 2017

xmik Aug 6, 2017

balshetzer Aug 5, 2017

xmik Aug 6, 2017

balshetzer Aug 5, 2017

xmik Aug 6, 2017

balshetzer Aug 5, 2017

xmik Aug 6, 2017

xmik commented Aug 6, 2017

xmik commented Aug 6, 2017

balshetzer commented Aug 14, 2017

pasztorpisti Aug 15, 2017

xmik Aug 15, 2017

matttproud commented Aug 22, 2017

Return verbose errors why expected method call did not match #97

Return verbose errors why expected method call did not match #97

Conversation

xmik commented Aug 3, 2017

The benefits

This PR contains

You may not like

googlebot commented Aug 3, 2017

xmik commented Aug 3, 2017

googlebot commented Aug 3, 2017

xmik commented Aug 3, 2017

balshetzer left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

xmik commented Aug 6, 2017

xmik commented Aug 6, 2017

balshetzer commented Aug 14, 2017

Choose a reason for hiding this comment

Choose a reason for hiding this comment

matttproud commented Aug 22, 2017