Premature end of file while uploading to S3

[arohner]

I'm calling:

(amazonica.aws.s3/put-object bucket-name key-name (io/input-stream a-file) {:some :metadata} )

com.amazonaws.AmazonClientException: Unable to unmarshall error response (Premature end of file.). Response Code: 400, Response Text: Bad Request
    at com.amazonaws.http.AmazonHttpClient.handleErrorResponse(AmazonHttpClient.java:792)
    at com.amazonaws.http.AmazonHttpClient.executeHelper(AmazonHttpClient.java:421)
    at com.amazonaws.http.AmazonHttpClient.execute(AmazonHttpClient.java:232)
    at com.amazonaws.services.s3.AmazonS3Client.invoke(AmazonS3Client.java:3566)
    at com.amazonaws.services.s3.AmazonS3Client.putObject(AmazonS3Client.java:1434)
    at com.amazonaws.services.s3.AmazonS3Client.putObject(AmazonS3Client.java:1275)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(Method.java:483)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(Method.java:483)
    at clojure.lang.Reflector.invokeMatchingMethod(Reflector.java:93)
    at clojure.lang.Reflector.invokeInstanceMethod(Reflector.java:28)
    at amazonica.core$fn_call$fn__1614.invoke(core.clj:718)
    at amazonica.core$intern_function$fn__1633.doInvoke(core.clj:769)
    at clojure.lang.RestFn.invoke(RestFn.java:457)

I'm pretty sure this is caused by the S3Client being GC'd before the file is finished uploading, in amazonica.core/fn-call.

References:

• http://stackoverflow.com/questions/9952815/s3-java-client-fails-a-lot-with-premature-end-of-content-length-delimited-messa
• https://forums.aws.amazon.com/thread.jspa?threadID=83326
• https://github.com/weavejester/clj-aws-s3/issues/3

[mcohen01]

Appreciate the links. I'll take a look at this over the weekend Allen, the function that returns the S3Client is currently memoized. Are you seeing this exception only with very large files?

[bilus]

Have you had a chance to look into this? I experience different behaviour but after a whole day's worth of debugging I begin to think its due to garbage collection.

It's very difficult to recreate using a short fragment of code but it reliably occurs in production (aot) -- when the user triggers upload after ~10 second pause, it fails with "Upload canceled". It doesn't occur if uploads are ran every 3 seconds. Any thoughts?

The reason I'm thinking along garbage collection lines is this line of code:

(amazonica.core/set-client AmazonS3Client (find-ns 'amazonica.aws.s3))

If it's triggered right before an upload, the problem seems to be gone.

UPDATE: It isn't gone, it just appears to show up less often.

In any case, this is the stack trace:

com.amazonaws.AmazonClientException: Upload canceled
    retryable: true
com.amazonaws.services.s3.transfer.internal.UploadMonitor.call       UploadMonitor.java:  142
com.amazonaws.services.s3.transfer.internal.UploadMonitor.call       UploadMonitor.java:   50
                           java.util.concurrent.FutureTask.run          FutureTask.java:  266
             java.util.concurrent.ThreadPoolExecutor.runWorker  ThreadPoolExecutor.java: 1142
            java.util.concurrent.ThreadPoolExecutor$Worker.run  ThreadPoolExecutor.java:  617
                                          java.lang.Thread.run              Thread.java:  745

[mcohen01]

I haven't looked into it much. As far as gc goes, it's worth noting that the AmazonS3Client (or any *Client) is memoized.

[bilus]

Yes, I've reviewed the code and it seems that nothing should get garbage-collected. It's a very tough problem but it shows up very reliably in our production code (we've worked around it by retrying uploads).

Apart from AmazonS3Client, is there any state shared between calls to upload? TransferManager seems to be created from scratch as is UploadManager (which appears to be the place where "Upload canceled" can be raised) so on the whole seems odd that it fails on the first upload, succeeds on an upload that follows within a very brief time span. Then you wait 10 seconds and it fails again. Same credentials, same file etc.

On Thu, Feb 26, 2015 at 3:41 AM, Michael Cohen [email protected] wrote:

I haven't looked into it much. As far as gc goes, it's worth noting that the AmazonS3Client (or any *Client) is memoized https://github.com/mcohen01/amazonica/blob/master/src/amazonica/core.clj#L234.

— Reply to this email directly or view it on GitHub https://github.com/mcohen01/amazonica/issues/65#issuecomment-76112324.

[mcohen01]

The TransferManager wasn't memoized, that's the only obvious thing to me from looking at the code. If you consistently see this issue, maybe you can run 0.3.19 and see if it's resolved or still there....

[bilus]

Thanks! For the time being the workaround works for us but we have it in our issue list so we're certainly going to look into this soon.

On Thu, Feb 26, 2015 at 11:20 PM, Michael Cohen [email protected] wrote:

The TransferManager wasn't memoized, that's the only obvious thing to me from looking at the code. If you consistently see this issue, maybe you can run 0.3.19 and see if it's resolved or still there....

— Reply to this email directly or view it on GitHub https://github.com/mcohen01/amazonica/issues/65#issuecomment-76287150.

[marco-m]

@bilus did you have a chance to test a more recent version of amazonica ? Is the bug still there or can this ticket be closed ?