HADOOP-17764. S3AInputStream read does not re-open the input stream on the second read retry attempt #3109

majdyz · 2021-06-16T10:35:41Z

NOTICE

Please create an issue in ASF JIRA before opening a pull request,
and you need to set the title of the pull request which starts with
the corresponding JIRA issue number. (e.g. HADOOP-XXXXX. Fix a typo in YYY.)
For more details, please see https://cwiki.apache.org/confluence/display/HADOOP/How+To+Contribute

steveloughran

Thanks for this.

Failure handling here is tricky here because it is relatively rare that it does happen, so are real world coverage maybe in adequate. One problem we have encountered in the past, which relates to this very section of code, is the challenge of making sure that retrys don't try and recycle the same HTTP connection which has just failed for a network error. There is something all the reviews will need to satisfy themselves with.

I say all the reviewers, as as I am on holiday this week. I nominate: @mukund-thakur @mehakmeet and @bogthe ... if any of you can comment, please do so

Testing

I can see you are deep into the S3A code base. This is good. It does mean though that you get to declare which S3 region you ran the full mvn verify test suites against. Thanks.
My opinions on mocking are fairly well known, as in "they are an utter nightmare from both future maintenance and back porting perspectives". This is that particular problem for me as I still have to backport stuff to mockito 1.x; and inevitably mocking-based tests will fail, leaving me to work out whether this is a real regression or just over-brittle tests. They are also incredibly brittle to any minor change in how different layers work. eg: any change in the s3 integration, a suite of mock tests suddenly fail and the developer is left to sort out if this is a regression or false alarm. If they cause too many problems I will just delete them.

I understand and we do use them occasionally for fault injection, but like to try and write code which can be tested without going near them; the callback interface design pattern has that as one of its goals.

S3AInputStreams now take an implementation of S3AInputStream.InputStreamCallbacks to open files. You shouldn't need to bind an S3AFS to a mock S3 client (with all the maintenance costs that implies) when a custom implementation of S3AInputStream.InputStreamCallbacks can be written for the test.

Accordingly: I don't think that you need to mock classes when 1+ callback implementation can trigger the failures in a way we can both backport and maintain in the future. This also means we don't need to make any more private methods VisibleForTesting.

no idea why yetus is complaining about TestS3AAWSCredentialsProvider.java. Unrelated, obviously.

hadoop-tools/hadoop-aws/src/test/java/org/apache/hadoop/fs/s3a/TestS3AInputStreamRetry.java

hadoop-tools/hadoop-aws/src/main/java/org/apache/hadoop/fs/s3a/S3AInputStream.java

hadoop-tools/hadoop-aws/src/test/java/org/apache/hadoop/fs/s3a/TestS3AInputStreamRetry.java

…n the second read retry attempt

majdyz · 2021-06-17T13:46:06Z

Thanks for the review!
I have re-written the test to not use mockito mocking to trigger the failure, let me know if it looks good :)

bogthe

Thanks for this PR too!

To start off, I'll reiterate what Steve said, once you touch S3a code you would have to run the testing suite and comment on this PR what region you ran them and if they were successful or not.

For the test suite that was added TestS3AInputStreamRetry:

There's still a bit too much mocking going on. Out of everything the most important part is .getObjectContent() as this is what the read function uses, everything else that's not needed is just added complexity to the test;
It would be good to have some test cases which cover failure scenarios, not just the failures that are expected on "the happy path";

bogthe · 2021-06-17T20:53:48Z

hadoop-tools/hadoop-aws/src/main/java/org/apache/hadoop/fs/s3a/S3AInputStream.java

+    } catch (EOFException e) {
+      return -1;
+    } catch (IOException e) {
+      onReadFailure(e, length, e instanceof SocketTimeoutException);


I see you're calling onReadFailure with length instead of 1. Any reasoning for this?

That is used to calculate the range for a GetObjectRequest when the stream is being reopened. If it's intended then I would be curious of the impact it has on larger objects, have you done any testing around it?

This method is used on both read() and read(b, off, len) we use length = 1 for read() and variable length for read(b, off, len). It's intended to keep the current behaviour

@bogthe see calculateRequestLimit(); its only part of the information used to calculate the range. on random IO the range will be that of fs.s3a.readahead (unless the file is shorter). It's more important in read(buffer[]) as then the full buffer length is requested; if something is asking for a 2MB buffer then that's what it gets.

bogthe · 2021-06-17T21:17:23Z

hadoop-tools/hadoop-aws/src/test/java/org/apache/hadoop/fs/s3a/TestS3AInputStreamRetry.java

+    };
+  }
+
+  // Get mocked S3ObjectInputStream where we can trigger IOException to sumulate the read failure


nit*: sumulate -> simulate

bogthe · 2021-06-17T21:21:10Z

hadoop-tools/hadoop-aws/src/main/java/org/apache/hadoop/fs/s3a/S3AFileSystem.java

+  @VisibleForTesting
+  protected S3AReadOpContext createReadContext(


I'm not really convinced that this is needed. Check the main comment for details.

Since the read context attach the retry policy and the retry logic that being used by the input stream, this is seems to be the entry where we can get for the test without exposing many internal implementations.

Afraid we currently do. However, if we move to a builder API for that ReadOpContext then the test could construct something very minimal (would only need the Invoker ref). I'd support that change here as it would help future tests.

majdyz · 2021-06-21T11:00:23Z

Hi @bogthe thanks for the feedback.
Sorry for getting back on this late, I'm running the test right now and will get back on this soon.

And for the testing part:

Aside from the .getObjectContent() we also need to get the current implementation of the retry policy (the part where we have delay before the next retry) which attached in the S3AReadOpContext. I tried to keep the mocking minimum by only setting the behaviour of the inputStream, but to attach this we need to go from InputStreamCallbacks -> S3Object -> S3ObjectInputStream so two small mockings before that are needed. Let me know if there could be a better approach for this.
For the failure scenario, I provided these two tests where the current implementation breaks, let me know if there is any other scenario I should provide for the test

mukund-thakur · 2021-06-21T12:07:47Z

Really a corner case scenario. Nice catch.
Reviewed the code. It looks good.
From what I understand, we are trying to catch the SocketTimeoutException during second read as well and re-opening and throwing the exception.

Though I was wondering, can the same be achieved by always re-opening the stream and throwing exception such that invoker does the retry.

steveloughran · 2021-06-21T13:50:40Z

hadoop-tools/hadoop-aws/src/main/java/org/apache/hadoop/fs/s3a/S3AInputStream.java

+    } catch (EOFException e) {
+      return -1;
+    } catch (IOException e) {
+      onReadFailure(e, length, e instanceof SocketTimeoutException);


@bogthe see calculateRequestLimit(); its only part of the information used to calculate the range. on random IO the range will be that of fs.s3a.readahead (unless the file is shorter). It's more important in read(buffer[]) as then the full buffer length is requested; if something is asking for a 2MB buffer then that's what it gets.

hadoop-tools/hadoop-aws/src/test/java/org/apache/hadoop/fs/s3a/TestS3AInputStreamRetry.java

steveloughran · 2021-06-21T13:57:37Z

hadoop-tools/hadoop-aws/src/main/java/org/apache/hadoop/fs/s3a/S3AFileSystem.java

+  @VisibleForTesting
+  protected S3AReadOpContext createReadContext(


Afraid we currently do. However, if we move to a builder API for that ReadOpContext then the test could construct something very minimal (would only need the Invoker ref). I'd support that change here as it would help future tests.

steveloughran

You've done some good work here identifying a problem & coming up with a fix.

Afraid Yetus is unappy about style issues, including indentation and line with. You do you have to fix these. Line length it's a long-standing source of contention, but until the policy changes we have to live with it except in cases where it would actually make readability much worse.

I really like what you've done with the new test; it's set an example for new ones.

Regarding the production code: do we actually need to have that second attempt explicitly performed, now that it is identical to the first.

instead it can invoked once, and Invoker.retry() handling the failure there (SocketTimeoutException) is an idempotent retry entry.

The sole disadvantage with cutting it would be that the first retry triggers a sleep() of a few hundred millis. That's all though, and any costs related to re-negotiating a new HTTPS connection are already there. So let's just do that: remove the second attempt entirely, but make sure the connection is closed on a socket timeout so we don't get the same connection again.

Now, big question: Which S3 endpooint are you running the mvn verify tests against, and what parameters did you pass the maven?

We need something like "aws ireland" and -Dparallel-tests -DtestsThreadCount=7 -Dmarkers=keep -Dscale. We need the endpoint to make sure you've done that you diligence and the parameters so we can see what's the coverage is and what different configurations should any other people running the tests try.

(Ignore that Yetus complaint about deprecation. I understand what the issue is -created HADOOP-17768).

majdyz · 2021-06-22T08:29:20Z

Agreed on adding slight delay on second retry won't do any harm, I have updated the main code to only just throwing the exception without having any manual try.

I'm running the test on aws us-west-1 the command that I'm using is mvn verify -Dtest=TestS3A* -Dit.test=ITestS3A* -Dparallel-tests there were two failing test in ITestS3AContractDistCp which I don't think related let me re-run the test and see how it goes.

majdyz · 2021-06-22T10:26:12Z

I got an error that requires me to provide DynamoDB table to run the S3A test, is this expected?
Is there any workaround to not use it?

steveloughran · 2021-06-22T13:04:07Z

thanks for running the tests.

Can you run the entire suite (I.e in the hadoop-aws module, run mvn verify ... and leave out the -Dtest and -Dit.test bits
Paste in the stack traces of the distcp failures here. We'll look and see if they are related or not, based on our experience of flaky tests.

majdyz · 2021-06-23T16:23:38Z

Here are the failing tests:

org.apache.hadoop.tools.contract.AbstractContractDistCpTest#testDistCpWithIterator
org.junit.runners.model.TestTimedOutException: test timed out after 1800000 milliseconds
org.apache.hadoop.fs.contract.AbstractContractUnbufferTest#testUnbufferOnClosedFile
java.lang.AssertionError: failed to read expected number of bytes from stream. This may be transient Expected :1024 Actual :605
org.apache.hadoop.fs.s3a.ITestS3AInconsistency#testGetFileStatus
java.lang.AssertionError: getFileStatus should fail due to delayed visibility.
org.apache.hadoop.fs.contract.s3a.ITestS3AContractUnbuffer
java.lang.AssertionError: failed to read expected number of bytes from stream. This may be transient Expected :1024 Actual :605
org.apache.hadoop.fs.s3a.tools.ITestMarkerTool
java.nio.file.AccessDeniedException: : listObjects: com.amazonaws.services.s3.model.AmazonS3Exception: Access Denied (Service: Amazon S3; Status Code: 403; Error Code: AccessDenied; Request ID: FN0SQ82F85TGTZPW; S3 Extended Request ID: j1bhdYzzKkMVQqSgPDEPW7QQXMkVE+WJeLKP81l/qs7uF0RVx1xcUk2r6Wri4NQFlt/XE9W+FBo=; Proxy: null), S3 Extended Request ID: j1bhdYzzKkMVQqSgPDEPW7QQXMkVE+WJeLKP81l/qs7uF0RVx1xcUk2r6Wri4NQFlt/XE9W+FBo=:AccessDenied
org.apache.hadoop.fs.s3a.select.ITestS3SelectMRJob
org.apache.hadoop.fs.s3a.statistics.ITestAWSStatisticCollection
org.apache.hadoop.fs.s3a.auth.delegation.ITestDelegatedMRJob
java.nio.file.AccessDeniedException: s3a://osm-pds/planet/planet-latest.orc#_partition.lst: getFileStatus on s3a://osm-pds/planet/planet-latest.orc#_partition.lst: com.amazonaws.services.s3.model.AmazonS3Exception: Forbidden (Service: Amazon S3; Status Code: 403; Error Code: 403 Forbidden; Request ID: A1Y4D90WW452Q8A9; S3 Extended Request ID: b/IV48OeMEgTaxikC9raP+IiHVPve3rIeoVkCymMc5opNp/70Iyc0tY2WZ0zpixFl0w7WT3bBCQ=; Proxy: null), S3 Extended Request ID: b/IV48OeMEgTaxikC9raP+IiHVPve3rIeoVkCymMc5opNp/70Iyc0tY2WZ0zpixFl0w7WT3bBCQ=:403 Forbidden

steveloughran · 2021-06-23T19:41:08Z

Thanks for the detials.
I agree, these are all unrelated. Some of them we've seen before and I'd say "you are distant from your S3 bucket/slow network/overloaded laptop". There's a couple of new ones though, both with hints of security/permissions.

org.apache.hadoop.tools.contract.AbstractContractDistCpTest#testDistCpWithIterator
org.junit.runners.model.TestTimedOutException: test timed out after 1800000 milliseconds

probably a variant on (https://issues.apache.org/jira/browse/HADOOP-17628)[https://issues.apache.org/jira/browse/HADOOP-17628]: we need to make the test directory tree smaller. it'd make the test faster for all too. Patches welcome :)

org.apache.hadoop.fs.contract.AbstractContractUnbufferTest#testUnbufferOnClosedFile
java.lang.AssertionError: failed to read expected number of bytes from stream. This may be transient Expected :1024 Actual :605

you aren't alone here; its read() returning an undeful buffer. We can't switch to readFully() as the test really wants to call read(). Ignore it. Happens when I use many threads in parallel runs.

org.apache.hadoop.fs.contract.s3a.ITestS3AContractUnbuffer
java.lang.AssertionError: failed to read expected number of bytes from stream. This may be transient Expected :1024 Actual :605

same transient; ignore

org.apache.hadoop.fs.s3a.ITestS3AInconsistency#testGetFileStatus
java.lang.AssertionError: getFileStatus should fail due to delayed visibility.

Looks like you are seeing https://issues.apache.org/jira/browse/HADOOP-17457
Given S3 is now consistent, I'd fix this by removing the entire test suite :)

org.apache.hadoop.fs.s3a.tools.ITestMarkerTool
java.nio.file.AccessDeniedException: : listObjects: com.amazonaws.services.s3.model.AmazonS3Exception: Access Denied (Service: Amazon S3; Status Code: 403; Error Code: AccessDenied;

This is new. Can you file a JIRA with the stack trace, just so we have a history of it.
MarkerTool should just be trying to call listObjects under a path in the test dir.

org.apache.hadoop.fs.s3a.auth.delegation.ITestDelegatedMRJob
java.nio.file.AccessDeniedException: s3a://osm-pds/planet/planet-latest.orc#_partition.lst: getFileStatus on s3a://osm-pds/planet/planet-latest.orc#_partition.lst: com.amazonaws.services.s3.model.AmazonS3Exception: Forbidden (Service: Amazon S3; Status Code: 403; Error Code: 403 Forbidden; Request ID: A1Y4D90WW452Q8A9; S3 Extended Request ID: b/IV48OeMEgTaxikC9raP+IiHVPve3rIeoVkCymMc5opNp/70Iyc0tY2WZ0zpixFl0w7WT3bBCQ=; Proxy: null), S3 Extended Request ID: b/IV48OeMEgTaxikC9raP+IiHVPve3rIeoVkCymMc5opNp/70Iyc0tY2WZ0zpixFl0w7WT3bBCQ=:403 Forbidden

This is very new, which makes it interesting. If you are seeing this, it means it may surface in the wild. I suspect it's because you've got an IAM permission set up blocking access to this (public) dataset.

Can you file a JIRA with this too? I'll probably give you some tasks to find out more about the cause, but at least there'll be an indexed reference to the issue.

steveloughran

OK. production code all good; suggested one more test case for the tests. Other than that it's down to the minor style nits, including yetus complaints in https://ci-hadoop.apache.org/job/hadoop-multibranch/job/PR-3109/9/artifact/out/results-checkstyle-hadoop-tools_hadoop-aws.txt

+1 pending those changes; as usual, you'll need to do a test run in the hadoop-aws module. Don't worry about tests which want dynamoDB -but do tell me which of these tests there are. They should all be skipping/downgrading

hadoop-tools/hadoop-aws/src/test/java/org/apache/hadoop/fs/s3a/TestS3AInputStreamRetry.java

steveloughran · 2021-06-24T15:28:48Z

Final changes LGTM; if the test run is happy then it's ready to commit

majdyz · 2021-06-24T20:13:05Z

I have re-run all the hadoop-aws tests, only 2 failure tests so far, turns out to be an IAM configuration issue on my end for the rest of error. I explicitly allow osm-pds and landsat-pds bucket access and the account and the rest are working fine. Here are the 2 failures :

org.apache.hadoop.tools.contract.AbstractContractDistCpTest#testDistCpWithIterator
test timed out after 1800000 milliseconds
org.apache.hadoop.fs.s3a.ITestS3AInconsistency#testGetFileStatus
java.lang.AssertionError: getFileStatus should fail due to delayed visibility.

For the second test that you mentioned: https://issues.apache.org/jira/browse/HADOOP-17457,
it seems to be consistently failing on my end instead of flaky.

steveloughran · 2021-06-25T14:19:37Z

ok. just fix those line length checkstyles and we are good to merge. As these are just formatting, no need to rerun the tests.

regarding the second failure -I've updated the JIRA to "lets just cut it"; it's part of the fault injection of inconsistencies we needed to test S3Guard. Now s3 is consistent, just a needless failure

majdyz · 2021-06-25T16:38:12Z

There seems to be no complaint from Yetus now :)

steveloughran

yep, yetus is happy.
FWIW, sometimes yetus is wrong, but we try to minimise all complaints to the final few

…n the second read retry attempt (#3109) Contributed by Zamil Majdy. Change-Id: I680d9c425c920ff1a7cd4764d62e10e6ac78bee4

steveloughran · 2021-06-25T20:10:59Z

thanks. Merged to trunk then (locally) cherrypicked that to branch-3.3, ran the new test (and only that test!) and pushed up.

@majdyz thanks! your contribution is appreciated

steveloughran · 2021-07-05T19:55:56Z

Note: we could also backport to 3.2.x if you want to cherrypick the 3.3 changes and retest...then provide a new PR.

…n the second read retry attempt (apache#3109) Contributed by Zamil Majdy.

…put stream on the second read retry attempt (apache#3109) Contributed by Zamil Majdy. Change-Id: I680d9c425c920ff1a7cd4764d62e10e6ac78bee4

majdyz force-pushed the HADOOP-17764 branch 3 times, most recently from 163bfd4 to 7ba901e Compare June 16, 2021 12:33

apache deleted a comment from hadoop-yetus Jun 16, 2021

steveloughran requested changes Jun 16, 2021

View reviewed changes

majdyz force-pushed the HADOOP-17764 branch from 586ce69 to fee4ad7 Compare June 17, 2021 13:30

HADOOP-17764. S3AInputStream read does not re-open the input stream o…

94f18f0

…n the second read retry attempt

majdyz force-pushed the HADOOP-17764 branch from fee4ad7 to 94f18f0 Compare June 17, 2021 13:39

majdyz requested a review from steveloughran June 17, 2021 13:46

bogthe suggested changes Jun 17, 2021

View reviewed changes

apache deleted a comment from hadoop-yetus Jun 21, 2021

steveloughran added the fs/s3 changes related to hadoop-aws; submitter must declare test endpoint label Jun 21, 2021

apache deleted a comment from hadoop-yetus Jun 21, 2021

HADOOP-17764. Fix typo in comment

8e2ae64

steveloughran reviewed Jun 21, 2021

View reviewed changes

steveloughran requested changes Jun 21, 2021

View reviewed changes

HADOOP-17764. post-review changes

02ec4ae

majdyz requested a review from steveloughran June 23, 2021 16:29

steveloughran requested changes Jun 23, 2021

View reviewed changes

HADOOP-17764. post-review changes

bb23212

apache deleted a comment from hadoop-yetus Jun 24, 2021

majdyz requested a review from steveloughran June 24, 2021 20:13

HADOOP-17764. post-review changes

448b2ef

steveloughran approved these changes Jun 25, 2021

View reviewed changes

steveloughran merged commit ed5d10e into apache:trunk Jun 25, 2021

asfgit pushed a commit that referenced this pull request Jun 25, 2021

HADOOP-17764. S3AInputStream read does not re-open the input stream o…

80859d7

…n the second read retry attempt (#3109) Contributed by Zamil Majdy. Change-Id: I680d9c425c920ff1a7cd4764d62e10e6ac78bee4

apache deleted a comment from hadoop-yetus Jun 25, 2021

kiran-maturi pushed a commit to kiran-maturi/hadoop that referenced this pull request Nov 24, 2021

HADOOP-17764. S3AInputStream read does not re-open the input stream o…

b106f39

…n the second read retry attempt (apache#3109) Contributed by Zamil Majdy.

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

HADOOP-17764. S3AInputStream read does not re-open the input stream on the second read retry attempt #3109

HADOOP-17764. S3AInputStream read does not re-open the input stream on the second read retry attempt #3109

majdyz commented Jun 16, 2021

steveloughran left a comment

majdyz commented Jun 17, 2021

bogthe left a comment

bogthe Jun 17, 2021

majdyz Jun 21, 2021

steveloughran Jun 21, 2021

bogthe Jun 17, 2021

majdyz Jun 21, 2021

bogthe Jun 17, 2021

majdyz Jun 21, 2021

steveloughran Jun 21, 2021

majdyz commented Jun 21, 2021

mukund-thakur commented Jun 21, 2021

steveloughran Jun 21, 2021

steveloughran Jun 21, 2021

steveloughran left a comment

majdyz commented Jun 22, 2021 •

edited

Loading

majdyz commented Jun 22, 2021 •

edited

Loading

steveloughran commented Jun 22, 2021

majdyz commented Jun 23, 2021 •

edited

Loading

steveloughran commented Jun 23, 2021

steveloughran left a comment

steveloughran commented Jun 24, 2021

majdyz commented Jun 24, 2021

steveloughran commented Jun 25, 2021

majdyz commented Jun 25, 2021

steveloughran left a comment

steveloughran commented Jun 25, 2021

steveloughran commented Jul 5, 2021

		@VisibleForTesting
		protected S3AReadOpContext createReadContext(

HADOOP-17764. S3AInputStream read does not re-open the input stream on the second read retry attempt #3109

HADOOP-17764. S3AInputStream read does not re-open the input stream on the second read retry attempt #3109

Conversation

majdyz commented Jun 16, 2021

NOTICE

steveloughran left a comment

Choose a reason for hiding this comment

Testing

majdyz commented Jun 17, 2021

bogthe left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

majdyz commented Jun 21, 2021

mukund-thakur commented Jun 21, 2021

Choose a reason for hiding this comment

Choose a reason for hiding this comment

steveloughran left a comment

Choose a reason for hiding this comment

majdyz commented Jun 22, 2021 • edited Loading

majdyz commented Jun 22, 2021 • edited Loading

steveloughran commented Jun 22, 2021

majdyz commented Jun 23, 2021 • edited Loading

steveloughran commented Jun 23, 2021

steveloughran left a comment

Choose a reason for hiding this comment

steveloughran commented Jun 24, 2021

majdyz commented Jun 24, 2021

steveloughran commented Jun 25, 2021

majdyz commented Jun 25, 2021

steveloughran left a comment

Choose a reason for hiding this comment

steveloughran commented Jun 25, 2021

steveloughran commented Jul 5, 2021

majdyz commented Jun 22, 2021 •

edited

Loading

majdyz commented Jun 22, 2021 •

edited

Loading

majdyz commented Jun 23, 2021 •

edited

Loading