Upload s3 PUT failure for large files #19
Description
Upload failure on big files. It looks like some packets were dropped, s3 PUT of a part failed, and it wasn't retried. Part of icgc-storage-client.log:
2017-05-06 22:32:33,570 [pool-1-thread-6] INFO o.i.d.s.c.t.MemoryMappedParallelPartObjectTransport - Sending remaining part Part(partNumber=1155, partSize=20971520, offset=24201134080, url=https://s3.amazonaws.com/oconnor-test-bucket-4/data/ad83062c-a79d-5a1b-a854-93b14234c471?uploadId=NaeHGSbnbvOpfNXXJSx9s1QBlUdsFVDvw_Cxg3bWTOR8UrScqgRw0DVYDScSdaPiVews6gymwApcyYg8bnoB37B1kfXk4gTj5tX.RC7OtFpyFh1Xky2w0joFZ.LlN4ys&partNumber=1155&X-Amz-Algorithm=AWS4-HMAC-SHA256&X-Amz-Date=20170506T222916Z&X-Amz-SignedHeaders=host&X-Amz-Expires=604799&X-Amz-Credential=AKIAJOQOLPFUKB3FHVZQ%2F20170506%2Fus-east-1%2Fs3%2Faws4_request&X-Amz-Signature=1f4995386182b8af1c436d28e433f6b91761ce1c3b9e42f26bf342c4c48cce24, md5=null, sourceMd5=null)
2017-05-06 22:32:33,829 [pool-1-thread-5] INFO o.i.d.s.c.t.MemoryMappedParallelPartObjectTransport - Sending remaining part Part(partNumber=1156, partSize=20971520, offset=24222105600, url=https://s3.amazonaws.com/oconnor-test-bucket-4/data/ad83062c-a79d-5a1b-a854-93b14234c471?uploadId=NaeHGSbnbvOpfNXXJSx9s1QBlUdsFVDvw_Cxg3bWTOR8UrScqgRw0DVYDScSdaPiVews6gymwApcyYg8bnoB37B1kfXk4gTj5tX.RC7OtFpyFh1Xky2w0joFZ.LlN4ys&partNumber=1156&X-Amz-Algorithm=AWS4-HMAC-SHA256&X-Amz-Date=20170506T222916Z&X-Amz-SignedHeaders=host&X-Amz-Expires=604799&X-Amz-Credential=AKIAJOQOLPFUKB3FHVZQ%2F20170506%2Fus-east-1%2Fs3%2Faws4_request&X-Amz-Signature=ec871394e80c7e0377b694a39619b0171f7f9a638c53cf991e60b74bfda6cb2d, md5=null, sourceMd5=null)
2017-05-06 22:32:34,088 [pool-1-thread-3] INFO o.i.d.s.c.t.MemoryMappedParallelPartObjectTransport - Sending remaining part Part(partNumber=1157, partSize=20971520, offset=24243077120, url=https://s3.amazonaws.com/oconnor-test-bucket-4/data/ad83062c-a79d-5a1b-a854-93b14234c471?uploadId=NaeHGSbnbvOpfNXXJSx9s1QBlUdsFVDvw_Cxg3bWTOR8UrScqgRw0DVYDScSdaPiVews6gymwApcyYg8bnoB37B1kfXk4gTj5tX.RC7OtFpyFh1Xky2w0joFZ.LlN4ys&partNumber=1157&X-Amz-Algorithm=AWS4-HMAC-SHA256&X-Amz-Date=20170506T222916Z&X-Amz-SignedHeaders=host&X-Amz-Expires=604799&X-Amz-Credential=AKIAJOQOLPFUKB3FHVZQ%2F20170506%2Fus-east-1%2Fs3%2Faws4_request&X-Amz-Signature=15113d4003fcf259d044ac736843a4b38b31792167579cea67e6bb4001b0ae0f, md5=null, sourceMd5=null)
2017-05-06 22:32:34,099 [pool-1-thread-4] WARN o.i.d.s.c.t.StorageService - Failed to send part for part #837 : {}
org.springframework.web.client.ResourceAccessException: I/O error on PUT request for "https://s3.amazonaws.com/oconnor-test-bucket-4/data/ad83062c-a79d-5a1b-a854-93b14234c471": Read timed out; nested exception is java.net.SocketTimeoutException: Read timed out
at org.springframework.web.client.RestTemplate.doExecute(RestTemplate.java:633)
at org.springframework.web.client.RestTemplate.execute(RestTemplate.java:595)
at org.icgc.dcc.storage.client.transport.StorageService$3.doWithRetry(StorageService.java:182)
at org.icgc.dcc.storage.client.transport.StorageService$3.doWithRetry(StorageService.java:164)
at org.springframework.retry.support.RetryTemplate.doExecute(RetryTemplate.java:263)
at org.springframework.retry.support.RetryTemplate.execute(RetryTemplate.java:154)
at org.icgc.dcc.storage.client.transport.StorageService.uploadPart(StorageService.java:164)
at org.icgc.dcc.storage.client.transport.MemoryMappedParallelPartObjectTransport$1.call(MemoryMappedParallelPartObjectTransport.java:123)
at org.icgc.dcc.storage.client.transport.MemoryMappedParallelPartObjectTransport$1.call(MemoryMappedParallelPartObjectTransport.java:105)
at java.util.concurrent.FutureTask.run(FutureTask.java:266)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
at java.lang.Thread.run(Thread.java:745)
Caused by: java.net.SocketTimeoutException: Read timed out
at java.net.SocketInputStream.socketRead0(Native Method)
at java.net.SocketInputStream.socketRead(SocketInputStream.java:116)
at java.net.SocketInputStream.read(SocketInputStream.java:171)
at java.net.SocketInputStream.read(SocketInputStream.java:141)
at sun.security.ssl.InputRecord.readFully(InputRecord.java:465)
at sun.security.ssl.InputRecord.read(InputRecord.java:503)
at sun.security.ssl.SSLSocketImpl.readRecord(SSLSocketImpl.java:973)
at sun.security.ssl.SSLSocketImpl.readDataRecord(SSLSocketImpl.java:930)
at sun.security.ssl.AppInputStream.read(AppInputStream.java:105)
at java.io.BufferedInputStream.fill(BufferedInputStream.java:246)
at java.io.BufferedInputStream.read1(BufferedInputStream.java:286)
at java.io.BufferedInputStream.read(BufferedInputStream.java:345)
at sun.net.www.http.HttpClient.parseHTTPHeader(HttpClient.java:704)
at sun.net.www.http.HttpClient.parseHTTP(HttpClient.java:647)
at sun.net.www.protocol.http.HttpURLConnection.getInputStream0(HttpURLConnection.java:1569)
at sun.net.www.protocol.http.HttpURLConnection.getInputStream(HttpURLConnection.java:1474)
at java.net.HttpURLConnection.getResponseCode(HttpURLConnection.java:480)
at sun.net.www.protocol.https.HttpsURLConnectionImpl.getResponseCode(HttpsURLConnectionImpl.java:338)
at org.springframework.http.client.SimpleClientHttpResponse.getRawStatusCode(SimpleClientHttpResponse.java:52)
at org.springframework.http.client.AbstractClientHttpResponse.getStatusCode(AbstractClientHttpResponse.java:33)
at org.springframework.web.client.DefaultResponseErrorHandler.getHttpStatusCode(DefaultResponseErrorHandler.java:56)
at org.springframework.web.client.DefaultResponseErrorHandler.hasError(DefaultResponseErrorHandler.java:50)
at org.springframework.web.client.RestTemplate.handleResponse(RestTemplate.java:655)
at org.springframework.web.client.RestTemplate.doExecute(RestTemplate.java:620)
... 12 common frames omitted
2017-05-06 22:32:34,256 [pool-1-thread-2] INFO o.i.d.s.c.t.MemoryMappedParallelPartObjectTransport - Sending remaining part Part(partNumber=1158, partSize=20971520, offset=24264048640, url=https://s3.amazonaws.com/oconnor-test-bucket-4/data/ad83062c-a79d-5a1b-a854-93b14234c471?uploadId=NaeHGSbnbvOpfNXXJSx9s1QBlUdsFVDvw_Cxg3bWTOR8UrScqgRw0DVYDScSdaPiVews6gymwApcyYg8bnoB37B1kfXk4gTj5tX.RC7OtFpyFh1Xky2w0joFZ.LlN4ys&partNumber=1158&X-Amz-Algorithm=AWS4-HMAC-SHA256&X-Amz-Date=20170506T222916Z&X-Amz-SignedHeaders=host&X-Amz-Expires=604799&X-Amz-Credential=AKIAJOQOLPFUKB3FHVZQ%2F20170506%2Fus-east-1%2Fs3%2Faws4_request&X-Amz-Signature=2e3dd291475e8e0b7744e0608bb4b1269ae8ce865e00ee84989f7281455ffd8e, md5=null, sourceMd5=null)
2017-05-06 22:32:34,580 [pool-1-thread-5] INFO o.i.d.s.c.t.MemoryMappedParallelPartObjectTransport - Sending remaining part Part(partNumber=1159, partSize=20971520, offset=24285020160, url=https://s3.amazonaws.com/oconnor-test-bucket-4/data/ad83062c-a79d-5a1b-a854-93b14234c471?uploadId=NaeHGSbnbvOpfNXXJSx9s1QBlUdsFVDvw_Cxg3bWTOR8UrScqgRw0DVYDScSdaPiVews6gymwApcyYg8bnoB37B1kfXk4gTj5tX.RC7OtFpyFh1Xky2w0joFZ.LlN4ys&partNumber=1159&X-Amz-Algorithm=AWS4-HMAC-SHA256&X-Amz-Date=20170506T222916Z&X-Amz-SignedHeaders=host&X-Amz-Expires=604799&X-Amz-Credential=AKIAJOQOLPFUKB3FHVZQ%2F20170506%2Fus-east-1%2Fs3%2Faws4_request&X-Amz-Signature=a059a8c6024b47d3d8a19ee37d9c175785024e0c76d4796c074e7205e79bb1e6, md5=null, sourceMd5=null)
2017-05-06 22:32:34,727 [pool-1-thread-6] INFO o.i.d.s.c.t.MemoryMappedParallelPartObjectTransport - Sending remaining part Part(partNumber=1160, partSize=20971520, offset=24305991680, url=https://s3.amazonaws.com/oconnor-test-bucket-4/data/ad83062c-a79d-5a1b-a854-93b14234c471?uploadId=NaeHGSbnbvOpfNXXJSx9s1QBlUdsFVDvw_Cxg3bWTOR8UrScqgRw0DVYDScSdaPiVews6gymwApcyYg8bnoB37B1kfXk4gTj5tX.RC7OtFpyFh1Xky2w0joFZ.LlN4ys&partNumber=1160&X-Amz-Algorithm=AWS4-HMAC-SHA256&X-Amz-Date=20170506T222916Z&X-Amz-SignedHeaders=host&X-Amz-Expires=604799&X-Amz-Credential=AKIAJOQOLPFUKB3FHVZQ%2F20170506%2Fus-east-1%2Fs3%2Faws4_request&X-Amz-Signature=7e81736ec3016254234f2238f8c22f0c4aeb4c894d52a2873af98eaa7b1d7119, md5=null, sourceMd5=null)