[FLINK-17769] [runtime] Fix the order of log events on a task failure #12525

curcur · 2020-06-08T09:51:55Z

What is the purpose of the change

When a task failure occurs, the error of disposing of an operator is logged before the real rootcasue is printed, which is confusing.

This fix suppressed exception occurring in disposing of an operator and attached the exception together with the rootcause.

Brief change log

change disposeAllOperators(True) to throw suppressed exceptions instead of log the exception error first.

Verifying this change

Unit test: StreamTaskTest.testCleanUpExceptionSuppressing

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/Mesos, ZooKeeper: no
The S3 file system connector: no

Documentation

Does this pull request introduce a new feature? no

flinkbot · 2020-06-08T09:54:27Z

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 d2c8896 (Mon Jun 08 09:54:27 UTC 2020)

Warnings:

No documentation files were touched! Remember to keep the Flink docs up to date!

_{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 · 2020-06-08T10:19:11Z

CI report:

6414069 Azure: SUCCESS

Bot commands

The @flinkbot bot supports the following commands:

@flinkbot run travis re-run the last Travis build
@flinkbot run azure re-run the last Azure build

rkhachatryan

Thanks for the fix @curcur.

I think in its current form the PR has some unintended behavior, please see the comments below.

Besides that,

Can you please add a component to commit message according to guide?
Are you also going to fix logging in Task in this PR (maybe in a separate commit)?

flink-streaming-java/src/main/java/org/apache/flink/streaming/runtime/tasks/StreamTask.java

rkhachatryan

Thanks for the update @cuncur,

I've left some comments.

I also couldn't find the test mentioned in the PR description.

flink-streaming-java/src/main/java/org/apache/flink/streaming/runtime/tasks/StreamTask.java

curcur · 2020-06-15T08:25:47Z

I believe I have addressed most of the comments we have discussed on Friday (not necessarily exactly the same way mentioned here, but roughly the idea).

There are two most things left:

whether to unify the disposeAllOperators(true/false) logic
unit tests.

rkhachatryan

Thanks for the update @curcur .
I have only some minor comments.

I think the only thing after addressing (or discussing) them are the tests.

flink-streaming-java/src/main/java/org/apache/flink/streaming/runtime/tasks/StreamTask.java

curcur · 2020-06-17T05:08:48Z

I've updated the existing unit test case
StreamTaskTest.testCleanUpExceptionSuppressing

to test the suppressed exception here, which I think it should be enough.

The original exception is ExpectedTestException throw from invoke

The suppressed exception is thrown from disposalAllOperators(), and is matched as well.

rkhachatryan

Thanks for the update @curcur,
Production code looks good to me.
I've left some minor comments about the test.

rkhachatryan · 2020-06-17T11:51:14Z

flink-streaming-java/src/test/java/org/apache/flink/streaming/runtime/tasks/StreamTaskTest.java

-				throw ex;
-			}
+			Assert.assertTrue(ex.getCause() instanceof ExpectedTestException);
+			Assert.assertTrue(


nit: IDE suggests to replace assertTrue with assertEquals

If you replace the assertTrue with assertEquals as suggested by IDE, it will then ask to simplify the code.

I think assertTrue is better than assertEquals since we can achieve the same purpose with shorter code.

I'm fine with either option, but just to clarify: do you mean the number of characters in assertEquals?

I mean

Assert.assertTrue(ex.getCause() instanceof ExpectedTestException); vs.
Assert.assertEquals(True, ex.getCause() instanceof ExpectedTestException);

I clicked the little yellow blob on the left top, and that is what the IDE suggesting.

flink-streaming-java/src/test/java/org/apache/flink/streaming/runtime/tasks/StreamTaskTest.java

rkhachatryan

Thanks for updating the PR @curcur!
Looks good to me.

curcur · 2020-06-19T04:49:55Z

Thanks for updating the PR @curcur!
Looks good to me.

Thank you so much @rkhachatryan for reviewing the PR :-) Appreciated!

pnowojski

Thanks for the reviews and fix. It L(almost)GTM % one test issue.

flink-streaming-java/src/test/java/org/apache/flink/streaming/runtime/tasks/StreamTaskTest.java

When a task failure occurs, the error of disposing of an operator is logged before the real rootcasue is printed, which is confusing. This fix suppressed exception occurring in disposing of an operator and attached the exception together with the rootcause.

pnowojski

Thanks for the update LGTM :)

rmetzger added the review=description? label Jun 8, 2020

rkhachatryan requested changes Jun 8, 2020

View reviewed changes

rmetzger added the component=Runtime/Task label Jun 8, 2020

curcur force-pushed the wrong_order branch from d2c8896 to 9c986dc Compare June 11, 2020 06:11

rkhachatryan requested changes Jun 11, 2020

View reviewed changes

curcur force-pushed the wrong_order branch 2 times, most recently from 4ef5cb9 to 9048cfd Compare June 15, 2020 08:22

curcur force-pushed the wrong_order branch from 9048cfd to 0460067 Compare June 15, 2020 11:39

rkhachatryan requested changes Jun 15, 2020

View reviewed changes

curcur force-pushed the wrong_order branch 2 times, most recently from 2276d04 to b397c0b Compare June 17, 2020 05:06

rkhachatryan reviewed Jun 17, 2020

View reviewed changes

curcur force-pushed the wrong_order branch 2 times, most recently from 67be651 to 683ce55 Compare June 18, 2020 15:28

rkhachatryan approved these changes Jun 18, 2020

View reviewed changes

pnowojski reviewed Jun 19, 2020

View reviewed changes

flink-streaming-java/src/test/java/org/apache/flink/streaming/runtime/tasks/StreamTaskTest.java Outdated Show resolved Hide resolved

flink-streaming-java/src/test/java/org/apache/flink/streaming/runtime/tasks/StreamTaskTest.java Outdated Show resolved Hide resolved

curcur force-pushed the wrong_order branch from 683ce55 to 6414069 Compare June 22, 2020 05:02

pnowojski approved these changes Jun 22, 2020

View reviewed changes

pnowojski closed this Jun 22, 2020

curcur deleted the wrong_order branch July 20, 2020 03:35

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

[FLINK-17769] [runtime] Fix the order of log events on a task failure #12525

[FLINK-17769] [runtime] Fix the order of log events on a task failure #12525

curcur commented Jun 8, 2020 •

edited

flinkbot commented Jun 8, 2020

flinkbot commented Jun 8, 2020 •

edited

rkhachatryan left a comment •

edited

rkhachatryan left a comment

curcur commented Jun 15, 2020

rkhachatryan left a comment

curcur commented Jun 17, 2020

rkhachatryan left a comment

rkhachatryan Jun 17, 2020

curcur Jun 18, 2020 •

edited

rkhachatryan Jun 18, 2020

curcur Jun 18, 2020 •

edited

rkhachatryan left a comment

curcur commented Jun 19, 2020 •

edited

pnowojski left a comment

pnowojski left a comment

[FLINK-17769] [runtime] Fix the order of log events on a task failure #12525

[FLINK-17769] [runtime] Fix the order of log events on a task failure #12525

Conversation

curcur commented Jun 8, 2020 • edited

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 Jun 8, 2020

Automated Checks

Review Progress

flinkbot commented Jun 8, 2020 • edited

CI report:

rkhachatryan left a comment • edited

Choose a reason for hiding this comment

rkhachatryan left a comment

Choose a reason for hiding this comment

curcur commented Jun 15, 2020

rkhachatryan left a comment

Choose a reason for hiding this comment

curcur commented Jun 17, 2020

rkhachatryan left a comment

Choose a reason for hiding this comment

rkhachatryan Jun 17, 2020

Choose a reason for hiding this comment

curcur Jun 18, 2020 • edited

Choose a reason for hiding this comment

rkhachatryan Jun 18, 2020

Choose a reason for hiding this comment

curcur Jun 18, 2020 • edited

Choose a reason for hiding this comment

rkhachatryan left a comment

Choose a reason for hiding this comment

curcur commented Jun 19, 2020 • edited

pnowojski left a comment

Choose a reason for hiding this comment

pnowojski left a comment

Choose a reason for hiding this comment

curcur commented Jun 8, 2020 •

edited

flinkbot commented Jun 8, 2020 •

edited

rkhachatryan left a comment •

edited

curcur Jun 18, 2020 •

edited

curcur Jun 18, 2020 •

edited

curcur commented Jun 19, 2020 •

edited