You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@jclouds.apache.org by Nikola Knezevic <la...@gmail.com> on 2015/04/14 18:26:31 UTC

Problem with S3: SEVERE: error after writing 946176/16777216 bytes

Hi,

we're having a problem with writing to S3, where quite frequently we
get the above exception, reproduced here in its entirety:

SEVERE: error after writing 4534272/16777216 bytes to
http://kne.recreate.container.s3.amazonaws.com/testblob-16777216byte-tid0-it20
java.io.IOException: Error writing request body to server
    at sun.net.www.protocol.http.HttpURLConnection$StreamingOutputStream.checkError(HttpURLConnection.java:3205)
    at sun.net.www.protocol.http.HttpURLConnection$StreamingOutputStream.write(HttpURLConnection.java:3188)
    at com.google.common.io.CountingOutputStream.write(CountingOutputStream.java:53)
    at com.google.common.io.ByteStreams.copy(ByteStreams.java:179)
    at org.jclouds.http.internal.JavaUrlHttpCommandExecutorService.writePayloadToConnection(JavaUrlHttpCommandExecutorService.java:297)
    at org.jclouds.http.internal.JavaUrlHttpCommandExecutorService.convert(JavaUrlHttpCommandExecutorService.java:170)
    at org.jclouds.http.internal.JavaUrlHttpCommandExecutorService.convert(JavaUrlHttpCommandExecutorService.java:64)
    at org.jclouds.http.internal.BaseHttpCommandExecutorService.invoke(BaseHttpCommandExecutorService.java:91)
    at org.jclouds.rest.internal.InvokeHttpMethod.invoke(InvokeHttpMethod.java:90)
    at org.jclouds.rest.internal.InvokeHttpMethod.apply(InvokeHttpMethod.java:73)
    at org.jclouds.rest.internal.InvokeHttpMethod.apply(InvokeHttpMethod.java:44)
    at org.jclouds.rest.internal.DelegatesToInvocationFunction.handle(DelegatesToInvocationFunction.java:156)
    at org.jclouds.rest.internal.DelegatesToInvocationFunction.invoke(DelegatesToInvocationFunction.java:123)
    at com.sun.proxy.$Proxy52.putObject(Unknown Source)
    at org.jclouds.s3.blobstore.S3BlobStore.putBlob(S3BlobStore.java:273)
    at org.jclouds.aws.s3.blobstore.AWSS3BlobStore.putBlob(AWSS3BlobStore.java:94)
    at org.jclouds.s3.blobstore.S3BlobStore.putBlob(S3BlobStore.java:246)
    at net.soba143.knl.Recreate$1.run(Recreate.java:202)
    at java.lang.Thread.run(Thread.java:745)

Apr 14, 2015 4:14:10 PM org.jclouds.logging.jdk.JDKLogger logError
SEVERE: Cannot retry after server error, command is not replayable:
[method=org.jclouds.aws.s3.AWSS3Client.public abstract
java.lang.String
org.jclouds.s3.S3Client.putObject(java.lang.String,org.jclouds.s3.domain.S3Object,org.jclouds.s3.options.PutObjectOptions[])[kne.recreate.container,
[metadata=[key=testblob-16777216byte-tid0-it20, bucket=null, uri=null,
eTag=null, cacheControl=null,
contentMetadata=[contentDisposition=null, contentEncoding=null,
contentLanguage=null, contentLength=16777216, contentMD5=null,
contentType=application/unknown, expires=null], lastModified=null,
owner=null, storageClass=STANDARD, userMetadata={}]],
[Lorg.jclouds.s3.options.PutObjectOptions;@1c714f0e], request=PUT
http://kne.recreate.container.s3.amazonaws.com/testblob-16777216byte-tid0-it20
HTTP/1.1]
[WARNING]
org.jclouds.http.HttpResponseException: Error writing request body to
server connecting to PUT
http://kne.recreate.container.s3.amazonaws.com/testblob-16777216byte-tid0-it20
HTTP/1.1
    at org.jclouds.http.internal.BaseHttpCommandExecutorService.invoke(BaseHttpCommandExecutorService.java:113)
    at org.jclouds.rest.internal.InvokeHttpMethod.invoke(InvokeHttpMethod.java:90)
    at org.jclouds.rest.internal.InvokeHttpMethod.apply(InvokeHttpMethod.java:73)
    at org.jclouds.rest.internal.InvokeHttpMethod.apply(InvokeHttpMethod.java:44)
    at org.jclouds.rest.internal.DelegatesToInvocationFunction.handle(DelegatesToInvocationFunction.java:156)
    at org.jclouds.rest.internal.DelegatesToInvocationFunction.invoke(DelegatesToInvocationFunction.java:123)
    at com.sun.proxy.$Proxy52.putObject(Unknown Source)
    at org.jclouds.s3.blobstore.S3BlobStore.putBlob(S3BlobStore.java:273)
    at org.jclouds.aws.s3.blobstore.AWSS3BlobStore.putBlob(AWSS3BlobStore.java:94)
    at org.jclouds.s3.blobstore.S3BlobStore.putBlob(S3BlobStore.java:246)
    at com.ibm.icstore.Recreate$1.run(Recreate.java:202)
    at java.lang.Thread.run(Thread.java:745)
Caused by: java.io.IOException: Error writing request body to server
    at sun.net.www.protocol.http.HttpURLConnection$StreamingOutputStream.checkError(HttpURLConnection.java:3205)
    at sun.net.www.protocol.http.HttpURLConnection$StreamingOutputStream.write(HttpURLConnection.java:3188)
    at com.google.common.io.CountingOutputStream.write(CountingOutputStream.java:53)
    at com.google.common.io.ByteStreams.copy(ByteStreams.java:179)
    at org.jclouds.http.internal.JavaUrlHttpCommandExecutorService.writePayloadToConnection(JavaUrlHttpCommandExecutorService.java:297)
    at org.jclouds.http.internal.JavaUrlHttpCommandExecutorService.convert(JavaUrlHttpCommandExecutorService.java:170)
    at org.jclouds.http.internal.JavaUrlHttpCommandExecutorService.convert(JavaUrlHttpCommandExecutorService.java:64)
    at org.jclouds.http.internal.BaseHttpCommandExecutorService.invoke(BaseHttpCommandExecutorService.java:91)
    ... 11 more



The test spawns multiple threads and then each thread starts writing
16MB blobs to S3. Each blob is differently named, and the crux of the
code that does the writing is below. Note that this doesn't fail every
time, but it fails once in 2-3 runs (it fails more often on
Linux+OpenJDK than on Mac+Oracle JDK). Verified on both jclouds 1.8
and 1.9. Also, I manually delete the container before the test.

final int mytid = tid;
Random random = new Random(Thread.currentThread().hashCode());

for (int i = 1; i <= invocationCounter; i++)
{
    System.out.println("Starting round " + i);

    final BlobStore blobStore1 = blobStore;

    final String blobName = "testblob-" + blobSize + "byte" + "-tid" +
mytid + "-it" + i;
    final Blob blob = blobStore1.blobBuilder(blobName)
                        .payload(new FakeInputStream(random.nextInt(),
blobSize))
                        .contentLength(blobSize)
                        .build();

    assertNotNull(blob);

    final String etag = blobStore.putBlob(containerName, blob);
    System.out.println(Thread.currentThread().getId() + " putBlob
returns " + etag);
}

(the rest of the code is here: https://gist.github.com/knl/3b708bca6b31df629c38)

>From our initial investigation, S3 sends us a TCP RST after exchanging
many ACKs and after we send a bunch of 1-20k requests. I tried
fiddling with soTimeout and others, but to no avail.

Has anyone seen a similar problem? If not, what should we do to
prevent this from happening? All our runs on the CI platform fail
because a longer variant of this test keeps failing :(

Thanks,
Nikola

Re: Problem with S3: SEVERE: error after writing 946176/16777216 bytes

Posted by Nikola Knežević <la...@gmail.com>.
Nikola Knežević wrote:

> So, to add some additional points, this also happens with other
> HttpCommandExecutorServices, but less frequently. If I disable selective
> TCP ACK in the OS, the problem doesn't show up, but performance is
> horrible.

That was me pressing Send before reading the email once again. Sorry, 
selective TCP ACK doesn't play role here (possibly), I was disabling TCP 
window scaling.

Cheers,
Nikola


Re: Problem with S3: SEVERE: error after writing 946176/16777216 bytes

Posted by Nikola Knežević <la...@gmail.com>.
Nikola Knezevic wrote:
> Hi,
>
> we're having a problem with writing to S3, where quite frequently we
> get the above exception, reproduced here in its entirety:
>
> SEVERE: error after writing 4534272/16777216 bytes to
> http://kne.recreate.container.s3.amazonaws.com/testblob-16777216byte-tid0-it20
> java.io.IOException: Error writing request body to server
>      at sun.net.www.protocol.http.HttpURLConnection$StreamingOutputStream.checkError(HttpURLConnection.java:3205)
>      at sun.net.www.protocol.http.HttpURLConnection$StreamingOutputStream.write(HttpURLConnection.java:3188)
>      at com.google.common.io.CountingOutputStream.write(CountingOutputStream.java:53)
>      at com.google.common.io.ByteStreams.copy(ByteStreams.java:179)


So, to add some additional points, this also happens with other 
HttpCommandExecutorServices, but less frequently. If I disable selective 
TCP ACK in the OS, the problem doesn't show up, but performance is horrible.

Is anyone else seeing these issues?

Best,
Nikola



Re: Problem with S3: SEVERE: error after writing 946176/16777216 bytes

Posted by Andrew Gaul <ga...@apache.org>.
On Tue, Apr 14, 2015 at 06:26:31PM +0200, Nikola Knezevic wrote:
> we're having a problem with writing to S3, where quite frequently we
> get the above exception, reproduced here in its entirety:
>
> ...
> 
> The test spawns multiple threads and then each thread starts writing
> 16MB blobs to S3. Each blob is differently named, and the crux of the
> code that does the writing is below. Note that this doesn't fail every
> time, but it fails once in 2-3 runs (it fails more often on
> Linux+OpenJDK than on Mac+Oracle JDK). Verified on both jclouds 1.8
> and 1.9. Also, I manually delete the container before the test.
>
> ...
> 
> From our initial investigation, S3 sends us a TCP RST after exchanging
> many ACKs and after we send a bunch of 1-20k requests. I tried
> fiddling with soTimeout and others, but to no avail.
> 
> Has anyone seen a similar problem? If not, what should we do to
> prevent this from happening? All our runs on the CI platform fail
> because a longer variant of this test keeps failing :(

I reproduced your symptoms using an EC2 instance to reduce network
variability.  I found that creating a container with a random name works
around your symptoms.  Container operations have less consistent
semantics than object operations and it is possible that the delete
container from one run conflicts with the object operations from the
subsequent run.  Can you also test this?

You might also have a better experience if you use a reusable Payload
like ByteSource which allows the jclouds retry mechanism to work.
Despite you setting PROPERTY_MAX_RETRIES to 15, the InputStream payload
is not reusable so this is effectively 0.  In the example code you could
use something like TestUtils.randomByteSource[1].

[1] https://github.com/jclouds/jclouds/blob/master/core/src/test/java/org/jclouds/utils/TestUtils.java

-- 
Andrew Gaul
http://gaul.org/