Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Advance DatabaseDownloder unittest #4021

Closed

Conversation

undertome
Copy link
Contributor

High Level Overview of Change

This pull request aims to fix spurious failures in the DatabaseDownloader unit test by increasing a timeout value that purports to be the source of the false positives.

Context of Change

A timeout value that determines how long the test waits before indicating failure was increased. The error is not reproducible so, lest the issue recur, this PR introduces additional logging information that would hopefully shed some light on the cause.

Type of Change

  • Bug fix (non-breaking change which fixes an issue)
  • New feature (non-breaking change which adds functionality)
  • Breaking change (fix or feature that would cause existing functionality to not work as expected)
  • Refactor (non-breaking change that only restructures code)
  • Tests (You added tests for code that already exists, or your new feature included in this PR)
  • Documentation Updates
  • Release

Future Tasks

Should the failure persist, consult the log output to assist in diagnosing the issue.

@undertome undertome added Bug Tech Debt Non-urgent improvements labels Dec 8, 2021
@scottschurr scottschurr self-assigned this Dec 13, 2021
Copy link
Collaborator

@scottschurr scottschurr left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This looks pretty good. However I think there are a few things that could be tidied up in this pull request. I left a few comments, which I'm happy to discuss. I also have a commit that you can look at in case you have questions about what I meant with the comments:

https://github.com/scottschurr/rippled/commits/devon-database-downloader-unittest

Feel free to cherry-pick the commit if you wish, but please don't feel obligated. You may have yet better ways to address the comments I left.

auto stat = cv.wait_for(lk, timeout, [this] { return called; });

auto stat = cv.wait_for(
lk, std::chrono::seconds(10), [this] { return called; });
Copy link
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I agree that there's no point in minimizing the timeout. The condition_variable should pull us out of the wait before this timeout in any non-failing case. In a failing case it's okay to wait a bit longer.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Yup, my thoughts exactly

@@ -143,6 +140,12 @@ class DatabaseDownloader_test : public beast::unit_test::suite
if (!BEAST_EXPECT(stat))
{
log << "Failed. LOGS:\n" + downloader.sink_.messages().str();
Copy link
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I'm gonna be really picky here. Sorry. I find it's useful to name things the same when they perform the same functions. Here I'm noticing that the Downloader is named downloader in testDownload. But it is consistently named dl in testFailures. I'd prefer that they have the same name throughout the file.

Conventions like this help to reduce brain fatigue. Think about how we consistently name all instances of Env env unless there's a really good reason not to.

Of the two names being used I have a slight preference for downloader. However I suspect you prefer dl. Either will be okay. In my opinion being consistent is more important in this case.

I'm gonna insist on it, I just think it's a really good idea.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

You remember my predilection for terse variable names.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Done

Comment on lines 253 to 257
log << "DownloadCompleter::waitComplete timed out. "
"DatabaseDownloader session active? "
<< std::boolalpha << dl->sessionIsActive()
<< " DatabaseDownloader is stopping? " << std::boolalpha
<< dl->isStopping() << std::endl;
Copy link
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I'm seeing a lot of repetition in the formatting of the output for these error cases. I think it would be much better if you wrote a function that you could call to format the output.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Done

Comment on lines 64 to 68
bool
sessionIsActive();

bool
isStopping();
Copy link
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

These are not const correct. They should be bool methodName() const;. In order to do that you'll need to make member variable m_ mutable. That was an oversight in the original design. m_ should have been mutable all along.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I considered making these things const and mutable then decided against it

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Done

Comment on lines 143 to 147
log << "DownloadCompleter::waitComplete timed out. "
"DatabaseDownloader session active? "
<< std::boolalpha << downloader->sessionIsActive()
<< " DatabaseDownloader is stopping? " << std::boolalpha
<< downloader->isStopping() << std::endl;
Copy link
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

We have a really hard time getting access to unit test output in CI. The only thing I know we consistently can see is fail output. So my inclination is to turn these log writes into fail writes. It would look something like this:

        std::stringstream ss;
        ss << "\nDownloadCompleter::waitComplete timed out."
              "\nDatabaseDownloader session active? "
           << std::boolalpha << downloader->sessionIsActive()
           << "\nDatabaseDownloader is stopping? " << std::boolalpha
           << downloader->isStopping();
        fail(ss.str(), file, line);

I think this change would make it much more likely we would see the output if we get CI failures in the future.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Done

<< " DatabaseDownloader is stopping? " << std::boolalpha
<< downloader->isStopping() << std::endl;

log << "Failed. LOGS:\n" + dl.sink_.messages().str();
Copy link
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This is now the only write in this file going to log, the rest are going to fail messages. And it lost much of what was being reported before. Is all of this intentional?

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This isn't a Downloader callback failure, so I wasn't compelled to provide the additional log information.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Made the failure reporting function more generic and included it here as well. Done

@@ -29,6 +28,8 @@
namespace ripple {
namespace test {

#define REPORT_FAILURE(D) reportFailure(D, __FILE__, __LINE__);
Copy link
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

After a night's sleep, I have a couple of suggestions regarding the REPORT_FAILURE macro.

A) Macros work by text substitution. Since you're including the semicolon in your macro, the places that invoke your macro and include the terminating semicolon actually have two semicolons — the explicit semicolon plus the one from the macro. That's not the end of the world.

However this also allows the person who's maintaining the code to accidentally omit the explicit closing semicolon. That's also not the end of the world, but it looks weird to other people reading the code.

You can avoid all these concerns by removing the closing semicolon from the REPORT_FAILURE macro. Consider it.

B) Macros have no scope. So once they are defined they affect everything that follows in the transaction unit. We usually expect a translation unit to end at the conclusion a *.cpp file. So we don't expect a macro that's defined below the #includes in a *.cpp file to leak into any other files.

However rippled can optionally be built in a unity style. For unity builds multiple *.cpp files are concatenated into a single translation unit. Suddenly the macro you thought was only affecting your own *.cpp file has leaked into other *.cpp files. That usually doesn't create any problems. But when it does those kinds of problems can be really hard to figure out.

The way to avoid complications like this in unity builds is to explicitly "scope" your macro. I suggest you #undef REPORT_FAILURE near the end of the file. This way the macro will not be able to leak into other files.

Suggestions Summary:

  1. Remove the closing semicolon from the REPORT_FAILURE macro.
  2. #undef REPORT_FAILURE toward the bottom of the file.

Sorry I didn't catch these earlier.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Good catch

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Done

Copy link
Collaborator

@scottschurr scottschurr left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

👍 LGTM. Thanks for addressing this.

@undertome
Copy link
Contributor Author

Squashed PR commits and rebased onto HEAD of develop

Copy link
Collaborator

@seelabs seelabs left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

👍 LGTM

Copy link
Collaborator

@seelabs seelabs left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

One nit: we should improve the commit message. "Advance DatabaseDownloader unittest" doesn't describe what's in the patch or the motivation for the patch.

@undertome
Copy link
Contributor Author

One nit: we should improve the commit message. "Advance DatabaseDownloader unittest" doesn't describe what's in the patch or the motivation for the patch.

Done

@ximinez ximinez added the Passed Passed code review & PR owner thinks it's ready to merge. Perf sign-off may still be required. label Apr 11, 2022
This was referenced May 10, 2022
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Bug Passed Passed code review & PR owner thinks it's ready to merge. Perf sign-off may still be required. Tech Debt Non-urgent improvements
Projects
None yet
Development

Successfully merging this pull request may close these issues.

4 participants