Storage - SocketException Socket closed (gcloud java 0.28)

[fondberg]

We still see StorageException caused by SocketExceptions even if they should have been retried.

java.net.SocketException: Socket is closed
    at sun.security.ssl.SSLSocketImpl.getInputStream
    at sun.net.www.http.HttpClient.parseHTTP
    at sun.net.www.protocol.http.HttpURLConnection.getInputStream0
    at sun.net.www.protocol.http.HttpURLConnection.getInputStream
    at java.net.HttpURLConnection.getResponseCode
    at sun.net.www.protocol.https.HttpsURLConnectionImpl.getResponseCode
    at com.google.api.client.http.javanet.NetHttpResponse.<init>
    at com.google.api.client.http.javanet.NetHttpRequest.execute
    at com.google.api.client.http.HttpRequest.execute
    at com.google.cloud.storage.spi.DefaultStorageRpc.open
    at com.google.cloud.storage.BlobWriteChannel.<init>
    at com.google.cloud.storage.StorageImpl.writer
    at com.google.cloud.storage.StorageImpl.writer
    at com.google.cloud.storage.StorageImpl.writer
    at com.spotify.buildartifactarchiver.storage.GcsUploaderClient.storeInputStream
    at com.spotify.buildartifactarchiver.storage.ArtifactUploader.uploadZipArchive
    at com.spotify.buildartifactarchiver.storage.ArtifactUploader.upload
    at com.spotify.buildartifactarchiver.ArtifactArchiver.archiveArtifactsForBuild
    at com.spotify.buildartifactarchiver.ArtifactArchiver.archiveBuild
    at com.spotify.buildartifactarchiver.web.ArtifactArchiverPubSubResource.messageHandler
    at com.spotify.google.cloud.pubsub.client.Puller.lambda$pullBatch$11
    at java.util.concurrent.CompletableFuture.uniWhenComplete
    at java.util.concurrent.CompletableFuture$UniWhenComplete.tryFire
    at java.util.concurrent.CompletableFuture.postComplete
    at java.util.concurrent.CompletableFuture.complete
    at com.spotify.google.cloud.pubsub.client.PubsubFuture.succeed
    at com.spotify.google.cloud.pubsub.client.PubsubFuture.lambda$wrap$9
    at java.util.concurrent.CompletableFuture.uniWhenComplete
    at java.util.concurrent.CompletableFuture$UniWhenComplete.tryFire
    at java.util.concurrent.CompletableFuture.postComplete
    at java.util.concurrent.CompletableFuture.complete
    at com.spotify.google.cloud.pubsub.client.PubsubFuture.succeed
    at com.spotify.google.cloud.pubsub.client.Pubsub.lambda$requestJavaNet$8
    at java.util.concurrent.ThreadPoolExecutor.runWorker
    at java.util.concurrent.ThreadPoolExecutor$Worker.run
    at java.lang.Thread.run
com.google.cloud.storage.StorageException: Socket is closed
    at com.google.cloud.storage.spi.DefaultStorageRpc.translate
    at com.google.cloud.storage.spi.DefaultStorageRpc.open
    at com.google.cloud.storage.BlobWriteChannel.<init>
    at com.google.cloud.storage.StorageImpl.writer
    at com.google.cloud.storage.StorageImpl.writer
    at com.google.cloud.storage.StorageImpl.writer
    at com.spotify.buildartifactarchiver.storage.GcsUploaderClient.storeInputStream
    at com.spotify.buildartifactarchiver.storage.ArtifactUploader.uploadZipArchive
    at com.spotify.buildartifactarchiver.storage.ArtifactUploader.upload
    at com.spotify.buildartifactarchiver.ArtifactArchiver.archiveArtifactsForBuild
    at com.spotify.buildartifactarchiver.ArtifactArchiver.archiveBuild
    at com.spotify.buildartifactarchiver.web.ArtifactArchiverPubSubResource.messageHandler
    at com.spotify.google.cloud.pubsub.client.Puller.lambda$pullBatch$11
    at java.util.concurrent.CompletableFuture.uniWhenComplete
    at java.util.concurrent.CompletableFuture$UniWhenComplete.tryFire
    at java.util.concurrent.CompletableFuture.postComplete
    at java.util.concurrent.CompletableFuture.complete
    at com.spotify.google.cloud.pubsub.client.PubsubFuture.succeed
    at com.spotify.google.cloud.pubsub.client.PubsubFuture.lambda$wrap$9
    at java.util.concurrent.CompletableFuture.uniWhenComplete
    at java.util.concurrent.CompletableFuture$UniWhenComplete.tryFire
    at java.util.concurrent.CompletableFuture.postComplete
    at java.util.concurrent.CompletableFuture.complete
    at com.spotify.google.cloud.pubsub.client.PubsubFuture.succeed
    at com.spotify.google.cloud.pubsub.client.Pubsub.lambda$requestJavaNet$8
    at java.util.concurrent.ThreadPoolExecutor.runWorker
    at java.util.concurrent.ThreadPoolExecutor$Worker.run
    at java.lang.Thread.run

We are uploading files using the following code if there is something that we might be doing wrong...

  public void storeInputStream(InputStream input, String fileName, String contentType)
      throws IOException {

    Storage storage = getStorage();

    BlobId blobId = BlobId.of(this.bucketName, fileName);
    LOG.debug("blobId: {}", blobId);
    BlobInfo blobInfo = BlobInfo.builder(blobId).contentType(contentType).build();
    LOG.debug("blobInfo: {}", blobInfo);
    LOG.info("Starting upload to GCS for file: {} with content type:{}", fileName, contentType);
    //perform stream uploads of the InputStream
    try (WriteChannel writer = storage.writer(blobInfo)) {
      byte[] buffer = new byte[1024];
      int limit;
      while ((limit = input.read(buffer)) >= 0) {
        writer.write(ByteBuffer.wrap(buffer, 0, limit));
      }
    }
  }

[mziccard]

Hi @fonzy2013,

this is odd but I might have an answer.

What is odd:

• You are getting java.net.SocketException: Socket is closed when opening a resumable session, not when uploading data. This is odd as calls to open do not carry a lot of data with them (few bytes) and should therefore be less susceptible to timeouts/network disruptions (or whatever it is that is causing this weird exception) while in progress.

Why this is happening:

• Calls to open in WriteChannel are not retried, not sure why

Good news:

• I can fix this right away by adding our retry logic to open calls in WriteChannel

I am sorry you are experiencing these issues, and I thank you for reporting them.

[fondberg]

@mziccard Thanks for speedy and great advice/support!
Strange indeed. Might it be a network related socket closure?

Now we are in production and only after 3 hours I saw around 150 exceptions (around 1-2% failure rate) which isn't all that bad but still ;-)

[mziccard]

around 1-2% failure rate

All these exceptions originate from a SocketException Socket closed exception with com.google.cloud.storage.spi.DefaultStorageRpc.open in the stacktrace? @Capstan what do you think about this failure rate?

Once again, adding retryals will mitigate this issue, I'll draft a PR ASAP.