[
https://issues.apache.org/jira/browse/HADOOP-17338?focusedWorklogId=510780&page=com.atlassian.jira.plugin.system.issuetabpanels:worklog-tabpanel#worklog-510780
]
ASF GitHub Bot logged work on HADOOP-17338:
-------------------------------------------
Author: ASF GitHub Bot
Created on: 12/Nov/20 12:58
Start Date: 12/Nov/20 12:58
Worklog Time Spent: 10m
Work Description: steveloughran commented on a change in pull request
#2455:
URL: https://github.com/apache/hadoop/pull/2455#discussion_r522082082
##########
File path:
hadoop-tools/hadoop-aws/src/main/java/org/apache/hadoop/fs/s3a/S3AInputStream.java
##########
@@ -578,25 +583,31 @@ private void closeStream(String reason, long length,
boolean forceAbort) {
streamStatistics.streamClose(false, drained);
} catch (Exception e) {
// exception escalates to an abort
- LOG.debug("When closing {} stream for {}", uri, reason, e);
+ LOG.warn("When closing {} stream for {}, will abort the stream",
uri, reason, e);
shouldAbort = true;
}
}
if (shouldAbort) {
// Abort, rather than just close, the underlying stream. Otherwise,
the
// remaining object payload is read from S3 while closing the stream.
- LOG.debug("Aborting stream");
- wrappedStream.abort();
+ LOG.warn("Aborting stream {}", uri);
Review comment:
revert to debug. We abort() a lot as week seek round files if read
policy != random, and don't want application logs overloaded with messages
##########
File path:
hadoop-tools/hadoop-aws/src/main/java/org/apache/hadoop/fs/s3a/S3AInputStream.java
##########
@@ -87,6 +87,7 @@
* set
*/
private volatile boolean closed;
+ private S3Object object;
Review comment:
can you add a javadoc comment explaining why this is needed "we have to
keep a reference to this to stop garbage collection breaking the input stream"
##########
File path:
hadoop-tools/hadoop-aws/src/main/java/org/apache/hadoop/fs/s3a/S3AInputStream.java
##########
@@ -431,8 +432,9 @@ public synchronized int read() throws IOException {
private void onReadFailure(IOException ioe, int length, boolean forceAbort)
throws IOException {
- LOG.info("Got exception while trying to read from stream {}" +
- " trying to recover: " + ioe, uri);
+ LOG.info("Got exception while trying to read from stream " + uri
+ + ", client: " + client + " object: " + object
Review comment:
why the change? The previous one used SLF4J expansion, and deliberately
only printed the IOEs message, not the stack.
If you want the stack, add a separate log at debug with the full details,
and use SL4J expansion of {} elements in the log string
##########
File path:
hadoop-tools/hadoop-aws/src/main/java/org/apache/hadoop/fs/s3a/S3AInputStream.java
##########
@@ -550,14 +552,17 @@ public synchronized void close() throws IOException {
*/
@Retries.OnceRaw
private void closeStream(String reason, long length, boolean forceAbort) {
- if (isObjectStreamOpen()) {
+ if (!isObjectStreamOpen())
Review comment:
nit: wrap in { }. Also add a comment "stream is already closed"
----------------------------------------------------------------
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
For queries about this service, please contact Infrastructure at:
[email protected]
Issue Time Tracking
-------------------
Worklog Id: (was: 510780)
Time Spent: 0.5h (was: 20m)
> Intermittent S3AInputStream failures: Premature end of Content-Length
> delimited message body etc
> ------------------------------------------------------------------------------------------------
>
> Key: HADOOP-17338
> URL: https://issues.apache.org/jira/browse/HADOOP-17338
> Project: Hadoop Common
> Issue Type: Bug
> Components: fs/s3
> Affects Versions: 3.3.0
> Reporter: Yongjun Zhang
> Assignee: Yongjun Zhang
> Priority: Major
> Labels: pull-request-available
> Attachments: HADOOP-17338.001.patch
>
> Time Spent: 0.5h
> Remaining Estimate: 0h
>
> We are seeing the following two kinds of intermittent exceptions when using
> S3AInputSteam:
> 1.
> {code:java}
> Caused by: com.amazonaws.thirdparty.apache.http.ConnectionClosedException:
> Premature end of Content-Length delimited message body (expected: 156463674;
> received: 150001089
> at
> com.amazonaws.thirdparty.apache.http.impl.io.ContentLengthInputStream.read(ContentLengthInputStream.java:178)
> at
> com.amazonaws.thirdparty.apache.http.conn.EofSensorInputStream.read(EofSensorInputStream.java:135)
> at
> com.amazonaws.internal.SdkFilterInputStream.read(SdkFilterInputStream.java:82)
> at com.amazonaws.event.ProgressInputStream.read(ProgressInputStream.java:180)
> at
> com.amazonaws.internal.SdkFilterInputStream.read(SdkFilterInputStream.java:82)
> at
> com.amazonaws.services.s3.internal.S3AbortableInputStream.read(S3AbortableInputStream.java:125)
> at
> com.amazonaws.internal.SdkFilterInputStream.read(SdkFilterInputStream.java:82)
> at
> com.amazonaws.internal.SdkFilterInputStream.read(SdkFilterInputStream.java:82)
> at
> com.amazonaws.internal.SdkFilterInputStream.read(SdkFilterInputStream.java:82)
> at com.amazonaws.event.ProgressInputStream.read(ProgressInputStream.java:180)
> at
> com.amazonaws.internal.SdkFilterInputStream.read(SdkFilterInputStream.java:82)
> at
> com.amazonaws.util.LengthCheckInputStream.read(LengthCheckInputStream.java:107)
> at
> com.amazonaws.internal.SdkFilterInputStream.read(SdkFilterInputStream.java:82)
> at org.apache.hadoop.fs.s3a.S3AInputStream.read(S3AInputStream.java:181)
> at java.io.DataInputStream.readFully(DataInputStream.java:195)
> at java.io.DataInputStream.readFully(DataInputStream.java:169)
> at
> org.apache.parquet.hadoop.ParquetFileReader$ConsecutiveChunkList.readAll(ParquetFileReader.java:779)
> at
> org.apache.parquet.hadoop.ParquetFileReader.readNextRowGroup(ParquetFileReader.java:511)
> at
> org.apache.parquet.hadoop.InternalParquetRecordReader.checkRead(InternalParquetRecordReader.java:130)
> at
> org.apache.parquet.hadoop.InternalParquetRecordReader.nextKeyValue(InternalParquetRecordReader.java:214)
> at
> org.apache.parquet.hadoop.ParquetRecordReader.nextKeyValue(ParquetRecordReader.java:227)
> at
> org.apache.hadoop.hive.ql.io.parquet.read.ParquetRecordReaderWrapper.next(ParquetRecordReaderWrapper.java:208)
> at
> org.apache.hadoop.hive.ql.io.parquet.read.ParquetRecordReaderWrapper.next(ParquetRecordReaderWrapper.java:63)
> at
> org.apache.hadoop.hive.ql.io.HiveContextAwareRecordReader.doNext(HiveContextAwareRecordReader.java:350)
> ... 15 more
> {code}
> 2.
> {code:java}
> Caused by: javax.net.ssl.SSLException: SSL peer shut down incorrectly
> at sun.security.ssl.InputRecord.readV3Record(InputRecord.java:596)
> at sun.security.ssl.InputRecord.read(InputRecord.java:532)
> at sun.security.ssl.SSLSocketImpl.readRecord(SSLSocketImpl.java:990)
> at sun.security.ssl.SSLSocketImpl.readDataRecord(SSLSocketImpl.java:948)
> at sun.security.ssl.AppInputStream.read(AppInputStream.java:105)
> at
> com.amazonaws.thirdparty.apache.http.impl.io.SessionInputBufferImpl.streamRead(SessionInputBufferImpl.java:137)
> at
> com.amazonaws.thirdparty.apache.http.impl.io.SessionInputBufferImpl.read(SessionInputBufferImpl.java:198)
> at
> com.amazonaws.thirdparty.apache.http.impl.io.ContentLengthInputStream.read(ContentLengthInputStream.java:176)
> at
> com.amazonaws.thirdparty.apache.http.conn.EofSensorInputStream.read(EofSensorInputStream.java:135)
> at
> com.amazonaws.internal.SdkFilterInputStream.read(SdkFilterInputStream.java:82)
> at com.amazonaws.event.ProgressInputStream.read(ProgressInputStream.java:180)
> at
> com.amazonaws.internal.SdkFilterInputStream.read(SdkFilterInputStream.java:82)
> at
> com.amazonaws.internal.SdkFilterInputStream.read(SdkFilterInputStream.java:82)
> at
> com.amazonaws.internal.SdkFilterInputStream.read(SdkFilterInputStream.java:82)
> at com.amazonaws.event.ProgressInputStream.read(ProgressInputStream.java:180)
> at
> com.amazonaws.internal.SdkFilterInputStream.read(SdkFilterInputStream.java:82)
> at
> com.amazonaws.util.LengthCheckInputStream.read(LengthCheckInputStream.java:107)
> at
> com.amazonaws.internal.SdkFilterInputStream.read(SdkFilterInputStream.java:82)
> at
> com.amazonaws.services.s3.internal.S3AbortableInputStream.read(S3AbortableInputStream.java:125)
> at
> com.amazonaws.internal.SdkFilterInputStream.read(SdkFilterInputStream.java:82)
> at org.apache.hadoop.fs.s3a.S3AInputStream.read(S3AInputStream.java:181)
> at java.io.DataInputStream.readFully(DataInputStream.java:195)
> at
> org.apache.hadoop.io.DataOutputBuffer$Buffer.write(DataOutputBuffer.java:70)
> at org.apache.hadoop.io.DataOutputBuffer.write(DataOutputBuffer.java:120)
> at org.apache.hadoop.io.SequenceFile$Reader.next(SequenceFile.java:2361)
> at org.apache.hadoop.io.SequenceFile$Reader.next(SequenceFile.java:2493)
> at
> org.apache.hadoop.mapred.SequenceFileRecordReader.next(SequenceFileRecordReader.java:82)
> at
> cascading.tap.hadoop.io.CombineFileRecordReaderWrapper.next(CombineFileRecordReaderWrapper.java:70)
> at
> org.apache.hadoop.mapred.lib.CombineFileRecordReader.next(CombineFileRecordReader.java:58)
> at
> org.apache.hadoop.mapred.MapTask$TrackedRecordReader.moveToNext(MapTask.java:199)
> at org.apache.hadoop.mapred.MapTask$TrackedRecordReader.next(MapTask.java:185)
> ... 10 more
> {code}
> Inspired by
>
> [https://stackoverflow.com/questions/9952815/s3-java-client-fails-a-lot-with-premature-end-of-content-length-delimited-messa]
> and
> [https://forums.aws.amazon.com/thread.jspa?threadID=83326], we got a
> solution that has helped us, would like to put the fix to the community
> version.
> The problem is that S3AInputStream had a short-lived S3Object which is used
> to create the wrappedSteam, and this object got garbage collected at random
> time, which caused the stream to be closed, thus the symptoms reported.
> [https://github.com/aws/aws-sdk-java/blob/1.11.295/aws-java-sdk-s3/src/main/java/com/amazonaws/services/s3/model/S3Object.java#L225]
> is the s3 code that closes the stream when S3 object is garbage collected:
> Here is the code in S3AInputStream that creates temporary S3Object and uses
> it to create the wrappedStream:
> {code:java}
> S3Object object = Invoker.once(text, uri,
> () -> client.getObject(request));
> changeTracker.processResponse(object, operation,
> targetPos);
> wrappedStream = object.getObjectContent();
> {code}
--
This message was sent by Atlassian Jira
(v8.3.4#803005)
---------------------------------------------------------------------
To unsubscribe, e-mail: [email protected]
For additional commands, e-mail: [email protected]
