HDDS-6113. Intermittent timeout in TestBlockOutputStreamWithFailures#testWatchForCommitDatanodeFailure

[raju-balpande]

What changes were proposed in this pull request?

Intermittent timeout in TestBlockOutputStreamWithFailuresFlushDelay#testDatanodeFailureWithSingleNodeRatis

TestBlockOutputStreamWithFailuresFlushDelay is changed to TestBlockOutputStreamWithFailures and observed the flakiness in method testWatchForCommitDatanodeFailure

I looked into the logic in test method, mostly it completes in 80s but in rare scenario it takes beyond 300s, I re-tested it with 600s and 900s but it still fails. When I run it with 1200s it succeed hence committed the change with timeout as 1200s.

What is the link to the Apache JIRA

https://issues.apache.org/jira/browse/HDDS-6113

How was this patch tested?

I tested it for 1000 runs with 50 splits and 20 iterations at https://github.com/raju-balpande/apache_ozone/actions/runs/9201973732

[adoroszlai]

Thanks @raju-balpande for working on this.

in rare scenario it takes beyond 300s, I re-tested it with 600s and 900s but it still fails. When I run it with 1200s it succeed hence committed the change with timeout as 1200s.

If the test usually passes in less than 2 minutes, but sometimes takes more than 15 minutes, we should see more variation in the execution time of successful splits when using 20 minutes timeout. But all splits passed around 1 hour, which indicates the "longer than 15 minutes" case was not hit in any of the runs.

So I doubt 20 minutes timeout is the solution. We'll need to check what is causing the delay.

An unrelated "fork timeout" problem (HDDS-10750) makes it more difficult to check results, so I suggest waiting until we can upgrade to Ratis 3.1.0, which should fix that.

[ivandika3]

@raju-balpande Thanks for the patch.

Could you check from the failed repeated tests whether the exception is due to the assertion exception mentioned in HDDS-6113 or are these mostly due to fork timeout?

As @adoroszlai said, HDDS-10750 might be the reason of the timeout.

[adoroszlai]

@ivandika3 I have checked some of the logs, and there are both kinds of timeouts:

test timeout: https://github.com/raju-balpande/apache_ozone/actions/runs/9226024466/job/25385130012#step:7:31517

fork timeout: https://github.com/raju-balpande/apache_ozone/actions/runs/9234289550/job/25461443504#step:7:32145

[ivandika3]

@adoroszlai Thanks for checking the timeouts.

We'll need to check what is causing the delay.

Agreed. Increasing the timeout significantly would mask the underlying problem.

[adoroszlai]

@ivandika3 however, even the test timeout seems to be due to the same underlying problem as HDDS-10750:

        at org.apache.ratis.server.impl.RaftServerImpl.lambda$close$3(RaftServerImpl.java:543)
        at org.apache.ratis.server.impl.RaftServerImpl$$Lambda$1923/1198603729.run(Unknown Source)
        at org.apache.ratis.util.LifeCycle.lambda$checkStateAndClose$7(LifeCycle.java:306)
        at org.apache.ratis.util.LifeCycle$$Lambda$1298/779888560.get(Unknown Source)
        at org.apache.ratis.util.LifeCycle.checkStateAndClose(LifeCycle.java:326)
        at org.apache.ratis.util.LifeCycle.checkStateAndClose(LifeCycle.java:304)
        at org.apache.ratis.server.impl.RaftServerImpl.close(RaftServerImpl.java:525)

So I think we can mark HDDS-6113 as duplicate.

[ivandika3]

@adoroszlai Sure, we can mark it as duplicate first.

[adoroszlai]

AssertionError: expected:<2> but was:<3> was last seen on 2023/08/30.

• https://github.com/adoroszlai/ozone-build-results/blob/master/2023/04/20/21694/it-client/output.log
• https://github.com/adoroszlai/ozone-build-results/blob/master/2023/04/21/21757/it-client/output.log
• https://github.com/adoroszlai/ozone-build-results/blob/master/2023/04/24/21817/it-flaky/output.log
• https://github.com/adoroszlai/ozone-build-results/blob/master/2023/05/18/22488/it-flaky/output.log
• https://github.com/adoroszlai/ozone-build-results/blob/master/2023/08/30/25045/it-flaky/output.log

[ivandika3]

@adoroszlai Noted, it's been a while. We can reopen the ticket if the assertion error happened again.

[raju-balpande]

Thanks, for the inputs on this request.