[FLINK-23914][connector/testing-framework] Improve logging and error message in testing framework #16940

PatrickRen · 2021-08-23T09:56:12Z

What is the purpose of the change

This pull request add debug logging for MultipleSplitDataMatcher used in testing framework if the case doesn't pass the validation of matcher.

Brief change log

Add debugging output if MultipleSplitDataMatcher fails

Verifying this change

This change is a trivial rework / code cleanup without any test coverage.

Does this pull request potentially affect one of the following parts:

Dependencies (does it add or upgrade a dependency): (no)
The public API, i.e., is any changed class annotated with @Public(Evolving): (no)
The serializers: (no)
The runtime per-record code paths (performance sensitive): (no)
Anything that affects deployment or recovery: JobManager (and its components), Checkpointing, Kubernetes/Yarn, ZooKeeper: (no)
The S3 file system connector: (no)

Documentation

Does this pull request introduce a new feature? (no)
If yes, how is the feature documented? (not applicable)

flinkbot · 2021-08-23T09:59:15Z

Thanks a lot for your contribution to the Apache Flink project. I'm the @flinkbot. I help the community
to review your pull request. We will use this comment to track the progress of the review.

Automated Checks

Last check on commit d2cb0d1 (Mon Aug 23 09:59:14 UTC 2021)

Warnings:

No documentation files were touched! Remember to keep the Flink docs up to date!
This pull request references an unassigned Jira ticket. According to the code contribution guide, tickets need to be assigned before starting with the implementation work.

_{Mention the bot in a comment to re-run the automated checks.}

Review Progress

❓ 1. The [description] looks good.
❓ 2. There is [consensus] that the contribution should go into to Flink.
❓ 3. Needs [attention] from.
❓ 4. The change fits into the overall [architecture].
❓ 5. Overall code [quality] is good.

Please see the Pull Request Review Guide for a full explanation of the review process.

The Bot is tracking the review progress through labels. Labels are applied according to the order of the review items. For consensus, approval by a Flink committer of PMC member is required

Bot commands

The @flinkbot bot supports the following commands:

@flinkbot approve description to approve one or more aspects (aspects: description, consensus, architecture and quality)
@flinkbot approve all to approve all aspects
@flinkbot approve-until architecture to approve everything until architecture
@flinkbot attention @username1 [@username2 ..] to require somebody's attention
@flinkbot disapprove architecture to remove an approval you gave earlier

flinkbot · 2021-08-23T10:23:55Z

CI report:

b1bf49b Azure: SUCCESS

Bot commands

The @flinkbot bot supports the following commands:

@flinkbot run azure re-run the last Azure build

AHeise

It seems that the Matcher provides insufficient information. I'd improve the mismatchDescription in any case. I'd probably just show the complete logCurrentProgress and just don't LOG.

AHeise · 2021-08-24T20:43:42Z

...or-testing/src/main/java/org/apache/flink/connectors/test/common/utils/TestDataMatchers.java

-                current = originalIterator.next();
-            } else {
-                current = null;
+        private void logCurrentProgress() {


Why is this not added to the mismatchDescription?

AHeise · 2021-08-24T20:45:13Z

...or-testing/src/main/java/org/apache/flink/connectors/test/common/utils/TestDataMatchers.java

@@ -151,11 +156,15 @@ protected boolean matchesSafely(Iterator<T> resultIterator, Description descript
                final T record = resultIterator.next();
                if (!matchThenNext(record)) {
                    mismatchDescription = String.format("Unexpected record '%s'", record);


Apparently this mismatch description is not very helpful. In the very least, I'd add offset and the expected record.

AHeise · 2021-08-24T20:45:58Z

...or-testing/src/main/java/org/apache/flink/connectors/test/common/utils/TestDataMatchers.java

+                mismatchDescription =
+                        "Number of records consumed from external system is less than "
+                                + "records written to external system";


This message apparently was also not very helpful. Could we add how many matched and which record is the first that didn't?

PatrickRen · 2021-09-08T06:20:30Z

Thanks @AHeise for the review! I made some refactor since your last review so you may want to review the PR again. I split changes into 4 commits:

47e181c changes the return type of ExternalContext#generateTestData from Collection to List because we need to preserve the order of test data
a257fbf improves mismatch descriptions as you commented above. Mismatch description will contain current progress of data validation if test fails
d113d7f adds INFO logs in basic test suite so that it's easier for user to track the behavior and progress of testing framework in logs
b1f1098 is a hotfix for re-enabling tests in PulsarSourceITCase, which is disabled temporarily on master

AHeise

Thank you very much. Looks very good already. I gave one more idea on how to improve the matching description.

AHeise · 2021-09-08T13:49:14Z

...esting/src/test/java/org/apache/flink/connectors/test/common/utils/TestDataMatchersTest.java

+            String expectedDescription =
+                    "Unexpected record '3' at position 6\n"
+                            + "Current progress of multiple split test data validation:\n"
+                            + "Split 0 (3/3): \n"
+                            + "alpha\n"
+                            + "beta\n"
+                            + "gamma\n"
+                            + "Split 1 (3/3): \n"
+                            + "one\n"
+                            + "two\n"
+                            + "three\n"
+                            + "Split 2 (0/3): \n"
+                            + "1\t<----\n"
+                            + "2\n"
+                            + "3\n";
+            assertMatcherFailedWithDescription(result.iterator(), matcher, expectedDescription);


Here it would be nice to also see the actual elements and not just the expected. For example, did we just receive incorrect output or was it swapped?

Thanks for the review @AHeise ! I appended the remaining received elements to the mismatchDescription in my latest push so that it can provide more info for debugging.

AHeise · 2021-10-06T08:39:28Z

Looks good already. Can you rebase on master and I'd do a final pass.

…tData returns List to preserve order

…st data matchers to reveal more info on failure

…ing stage of connector testing framework

AHeise · 2021-10-22T07:36:56Z

@flinkbot run azure

AHeise

LGTM. Thanks! Let's wait for a final AZP run.

PatrickRen · 2021-10-27T03:39:21Z

Thanks @AHeise ! AZP run has passed. Could you help to merge the PR when you are available?

AHeise · 2021-10-27T06:08:42Z

Thank you. Merged. Can you create a backport PR?

rmetzger added the review=description? label Aug 23, 2021

rmetzger added the component=Tests label Aug 23, 2021

AHeise reviewed Aug 24, 2021

View reviewed changes

PatrickRen force-pushed the testing-framework-verbose branch 2 times, most recently from 0cb0692 to b1f1098 Compare September 7, 2021 09:08

PatrickRen changed the title ~~[FLINK-23914][connector/testing-framework] Print debug log if multiple split data validation fails~~ [FLINK-23914][connector/testing-framework] Improve logging and error message in testing framework Sep 7, 2021

AHeise reviewed Sep 8, 2021

View reviewed changes

PatrickRen force-pushed the testing-framework-verbose branch from b1f1098 to 32f2f8c Compare September 10, 2021 15:10

PatrickRen added 3 commits October 11, 2021 15:01

[hotfix][connector/testing-framework] Let ExternalContext#generateTes…

6257275

…tData returns List to preserve order

[FLINK-23914][connector/testing-framework] Improve descriptions in te…

369c064

…st data matchers to reveal more info on failure

[FLINK-23914][connector/testing-framework] Add INFO log to track runn…

b1bf49b

…ing stage of connector testing framework

PatrickRen force-pushed the testing-framework-verbose branch from 32f2f8c to b1bf49b Compare October 11, 2021 07:26

AHeise approved these changes Oct 22, 2021

View reviewed changes

AHeise merged commit db1df30 into apache:master Oct 27, 2021

PatrickRen mentioned this pull request Oct 27, 2021

[BP-1.14][FLINK-23914][connector/testing-framework] Improve logging and error message in testing framework #17577

Merged

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

[FLINK-23914][connector/testing-framework] Improve logging and error message in testing framework #16940

[FLINK-23914][connector/testing-framework] Improve logging and error message in testing framework #16940

PatrickRen commented Aug 23, 2021

flinkbot commented Aug 23, 2021

flinkbot commented Aug 23, 2021 •

edited

AHeise left a comment

AHeise Aug 24, 2021

AHeise Aug 24, 2021

AHeise Aug 24, 2021

PatrickRen commented Sep 8, 2021

AHeise left a comment

AHeise Sep 8, 2021

PatrickRen Sep 10, 2021

AHeise commented Oct 6, 2021

AHeise commented Oct 22, 2021

AHeise left a comment

PatrickRen commented Oct 27, 2021

AHeise commented Oct 27, 2021

[FLINK-23914][connector/testing-framework] Improve logging and error message in testing framework #16940

[FLINK-23914][connector/testing-framework] Improve logging and error message in testing framework #16940

Conversation

PatrickRen commented Aug 23, 2021

What is the purpose of the change

Brief change log

Verifying this change

Does this pull request potentially affect one of the following parts:

Documentation

flinkbot commented Aug 23, 2021

Automated Checks

Review Progress

flinkbot commented Aug 23, 2021 • edited

CI report:

AHeise left a comment

Choose a reason for hiding this comment

AHeise Aug 24, 2021

Choose a reason for hiding this comment

AHeise Aug 24, 2021

Choose a reason for hiding this comment

AHeise Aug 24, 2021

Choose a reason for hiding this comment

PatrickRen commented Sep 8, 2021

AHeise left a comment

Choose a reason for hiding this comment

AHeise Sep 8, 2021

Choose a reason for hiding this comment

PatrickRen Sep 10, 2021

Choose a reason for hiding this comment

AHeise commented Oct 6, 2021

AHeise commented Oct 22, 2021

AHeise left a comment

Choose a reason for hiding this comment

PatrickRen commented Oct 27, 2021

AHeise commented Oct 27, 2021

flinkbot commented Aug 23, 2021 •

edited