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

MINIFICPP-1281 - Improve test performance by using event polling instead of sleep by sync #835

Closed

Conversation

hunyadi-dev
Copy link
Contributor

Decreases the avg. test execution time by 57% (from 326 seconds to 139 seconds).

Measurements on test times of master (on MacBook Pro 16-inch, 2019):

➜ for repetition in {1..5}; do; time ninja test 2>&1 >> test_logs.txt; done;
ninja test 2>&1 >> test_logs.txt  46.05s user 19.32s system 18% cpu 5:58.81 total
ninja test 2>&1 >> test_logs.txt  45.81s user 13.33s system 18% cpu 5:16.95 total
ninja test 2>&1 >> test_logs.txt  46.10s user 13.22s system 18% cpu 5:18.84 total
ninja test 2>&1 >> test_logs.txt  46.08s user 13.39s system 18% cpu 5:17.21 total
ninja test 2>&1 >> test_logs.txt  46.16s user 13.51s system 18% cpu 5:16.61 total
➜ grep "Total Test time" test_logs.txt
Total Test time (real) = 358.74 sec
Total Test time (real) = 316.88 sec
Total Test time (real) = 318.78 sec
Total Test time (real) = 317.14 sec
Total Test time (real) = 316.57 sec

On the source branch of this PR:

➜ for repetition in {1..5}; do; time ninja test 2>&1 >> test_logs.txt; done;
ninja test 2>&1 >> test_logs.txt  24.04s user 9.62s system 24% cpu 2:19.84 total
ninja test 2>&1 >> test_logs.txt  23.98s user 9.17s system 24% cpu 2:17.74 total
ninja test 2>&1 >> test_logs.txt  23.89s user 9.44s system 24% cpu 2:18.17 total
ninja test 2>&1 >> test_logs.txt  23.82s user 9.53s system 24% cpu 2:18.72 total
ninja test 2>&1 >> test_logs.txt  24.04s user 9.56s system 23% cpu 2:20.81 total
➜ grep "Total Test time" test_logs.txt
Total Test time (real) = 139.77 sec
Total Test time (real) = 137.68 sec
Total Test time (real) = 138.10 sec
Total Test time (real) = 138.66 sec
Total Test time (real) = 140.75 sec

@hunyadi-dev hunyadi-dev marked this pull request as draft July 8, 2020 14:06
@hunyadi-dev hunyadi-dev force-pushed the MINIFICPP-1281_caffeinated_tests branch from 4639d8d to e97d5f2 Compare July 8, 2020 15:19
@hunyadi-dev hunyadi-dev marked this pull request as ready for review July 8, 2020 15:22
@hunyadi-dev hunyadi-dev force-pushed the MINIFICPP-1281_caffeinated_tests branch from e97d5f2 to 3b9d6ed Compare July 9, 2020 16:18
Copy link
Contributor

@arpadboda arpadboda left a comment

Choose a reason for hiding this comment

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

Nice changes, added some comments.

Not sure if waitToVerifyProcessors should be thrown out, I think waiting for something and then asserting for something else is a valid scenario.

extensions/http-curl/tests/C2FailedUpdateTest.cpp Outdated Show resolved Hide resolved
libminifi/include/utils/IntegrationTestUtils.h Outdated Show resolved Hide resolved
libminifi/include/utils/IntegrationTestUtils.h Outdated Show resolved Hide resolved
@hunyadi-dev hunyadi-dev force-pushed the MINIFICPP-1281_caffeinated_tests branch from 3b9d6ed to 5e3fa22 Compare July 20, 2020 10:36
@hunyadi-dev hunyadi-dev changed the base branch from master to main July 20, 2020 12:24
@hunyadi-dev hunyadi-dev force-pushed the MINIFICPP-1281_caffeinated_tests branch from 5e3fa22 to c566ab5 Compare July 20, 2020 12:27
extensions/http-curl/tests/C2JstackTest.cpp Show resolved Hide resolved
extensions/http-curl/tests/C2UpdateTest.cpp Outdated Show resolved Hide resolved
@@ -34,6 +34,6 @@ int main(int argc, char **argv) {

const auto then = std::chrono::system_clock::now();
const auto seconds = std::chrono::duration_cast<std::chrono::seconds>(then - start).count();
assert(handler.calls_ <= (seconds) + 1);
assert(handler.calls_ <= (seconds) + 2);
Copy link
Member

Choose a reason for hiding this comment

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

What's the reason for this change?

Copy link
Contributor Author

Choose a reason for hiding this comment

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

Some libcurl black magic we do not understand. I could not figure it out but shared the problem with a group of contributors on Slack. I verified the logs and the events happening are what we expect, but curl immediately triggers the POST handle on the Civet Server twice. It was probably an issue beforehand masked by the long waiting time.

Copy link
Contributor Author

Choose a reason for hiding this comment

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

One of the CI jobs of @fgerlits had this issue earlier as well: https://travis-ci.org/github/apache/nifi-minifi-cpp/jobs/711468287

Seems like it is indeed the case that we had this error before, but masked it away with the long waiting.

@hunyadi-dev hunyadi-dev force-pushed the MINIFICPP-1281_caffeinated_tests branch from c566ab5 to 3a99397 Compare July 21, 2020 13:09
@hunyadi-dev hunyadi-dev force-pushed the MINIFICPP-1281_caffeinated_tests branch 4 times, most recently from 6423beb to b6a647f Compare July 28, 2020 07:56
Copy link
Member

@szaszm szaszm left a comment

Choose a reason for hiding this comment

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

const int occurrences = result.second;
return 1 < occurrences;
}));
flowController_->updatePropertyValue("kafka", minifi::processors::PublishKafka::MaxMessageSize.getName(), "1999");
Copy link
Member

Choose a reason for hiding this comment

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

What's the reason for the change of MaxMessageSize?

Copy link
Contributor Author

Choose a reason for hiding this comment

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

There is no change, it was previously in the waitToVerifyProcessor() on line 57.

Copy link
Contributor Author

Choose a reason for hiding this comment

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

At least I hope there is none :)

hunyadi-dev and others added 4 commits July 31, 2020 16:33
Update comment for verifyLogLinePresenceInPollTime

Co-authored-by: Ferenc Gerlits <fgerlits@users.noreply.github.com>
Co-authored-by: Márton Szász <szaszm@users.noreply.github.com>
@hunyadi-dev hunyadi-dev force-pushed the MINIFICPP-1281_caffeinated_tests branch from b6a647f to 825c1db Compare July 31, 2020 14:34
@arpadboda arpadboda closed this in 26f9991 Aug 3, 2020
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
5 participants