[tests/mock_logger] Add substr as Description() for distinction

[xmkg]

Right now, it's hard to tell which expect_log call is failed to be satisfied because the output is ambiguous:

 error: Actual function call count doesn't match EXPECT_CALL(*this, log(lvl, _, HasSubstr(substr)))...
         Expected: to be called once
           Actual: never called - unsatisfied and active

The patch fixes that by utilizing the matcher description:

 error: Actual function "my expected log string" call count doesn't match EXPECT_CALL(*this, log(lvl, _, HasSubstr(substr)))...
         Expected: to be called once
           Actual: never called - unsatisfied and active
```

[codecov]

Codecov Report

✅ All modified and coverable lines are covered by tests.
✅ Project coverage is 89.50%. Comparing base (b086fb7) to head (e8e9756).
⚠️ Report is 444 commits behind head on main.

Additional details and impacted files

@@           Coverage Diff           @@
##             main    #4074   +/-   ##
=======================================
  Coverage   89.50%   89.50%           
=======================================
  Files         259      259           
  Lines       14740    14740           
=======================================
  Hits        13193    13193           
  Misses       1547     1547           

☔ View full report in Codecov by Sentry.
📢 Have feedback on the report? Share it here.

🚀 New features to boost your workflow:

• ❄️ Test Analytics: Detect flaky tests, report on failures, and find test suite problems.

[ricab]

Good idea, but the sentence looks a little strange. Could do Description(fmt::format("log with {}", substr)) or maybe just use operator << ?

[xmkg]

Good idea, but the sentence looks a little strange. Could do Description(fmt::format("log with {}", substr)) or maybe just use operator << ?

Hmm, EXPECT_CALL does not seem to implement "operator <<". I agree that we could use a nicer message, though. How about sth like:

Actual function "expect_log(level: debug, substr: "message", times: 1)" call count doesn't match EXPECT_CALL(*this, log(lvl, _, HasSubstr(substr))).

[ricab]

Hmm, it's log whose call count doesn't match, not expect_log, right?

[xmkg]

Hmm, it's log whose call count doesn't match, not expect_log, right?

The main problem comes from the assumed placement of the description. It's right between the [actual] and [expected], and whatever we write into the description will be associated with the actual part as a cognitive default. Given that we don't have an easy way to manipulate this ordering, let's ditch the function name altogether then. How about:

Actual function "level: debug, substr: `message`" call count doesn't match EXPECT_CALL(*this, log(lvl, _, HasSubstr(substr))

[ricab]

There is maybe something I am missing, but why don't you say this?

Actual function "log(level: debug, substr: "message")" call count doesn't match EXPECT_CALL(*this, log(lvl, _, HasSubstr(substr))).

IOW, the actual call count for function log with those arguments didn't match the expectation. That would be accurate, no?

[xmkg]

There is maybe something I am missing, but why don't you say this?

Actual function "log(level: debug, substr: "message")" call count doesn't match EXPECT_CALL(*this, log(lvl, _, HasSubstr(substr))).

IOW, the actual call count for function log with those arguments didn't match the expectation. That would be accurate, no?

I suppose so. There's a slight disconnect between what we actually write in unit tests (expect_log) vs. what's actually being logged (log), but ok. I could live with that.

[ricab]

This makes sense to me, thanks!

Regarding the disconnect you mention, perhaps I haven't been sleeping enough and I may be short-circuiting, but expect_log is what the unit tests call to set a call-count expectation on log... That is what the message is saying doesn't match. If anything, it's EXPECT_CALL that could be replaced with expect_log (not necessary).

[xmkg]

Regarding the disconnect you mention, perhaps I haven't been sleeping enough and I may be short-circuiting, but expect_log is what the unit tests call to set a call-count expectation on log... That is what the message is saying doesn't match. If anything, it's EXPECT_CALL that could be replaced with expect_log (not necessary).

Yeah, log() is hidden behind the expect_log() call, so what I'm saying is it might be slightly harder to correlate the output with the actual unit test case, but that's not that important. I'd take any single clue that would lead to the correct expect_log() line when something goes wrong, so I don't have any strong preference on that.

Regarding the EXPECT_CALL part: unfortunately we can't easily touch the EXPECT_CALL part of the description. I agree that it would look much cleaner, but IMO it's not worth the effort.

[ricab]

Yeah, log() is hidden behind the expect_log() call [...]

EXPECT_CALL is — log() itself is called in the code being tested. But I understand what you mean better now. It would be good to have an indication of where the failed expect_log() was called in the tests. I agree what you have is good enough though 👍

[ricab]

Hey @xmkg to keep the web a little simpler, we normally avoid merging the target branch back into the topic branch and rebase instead (except if there are many commits with conflicts). Would you mind doing that here, please?

[xmkg]

Hey @xmkg to keep the web a little simpler, we normally avoid merging the target branch back into the topic branch and rebase instead (except if there are many commits with conflicts). Would you mind doing that here, please?

Done

[ricab]

Thank you!

[xmkg]

@georgeliao, can I get a secondary review when you're available? The changes are trivial.

[sharder996]

+1 from me

[xmkg]

+1 from me

Thanks Scott!

[ricab]

Hey @xmkg, I removed this from the queue to avoid having to rebase #4082 again, which is tricky due to the different authors and GPG keys. Sorry about that. We can add it back once that is done.