azure-sdk-for-java icon indicating copy to clipboard operation
azure-sdk-for-java copied to clipboard

Concurrency Issue with BlobOutputStream

Open vogeljd opened this issue 1 year ago • 4 comments

With versions of azure-storage-blob released after 12.25.4 I encountered an issue with uploading from BlobOutputStream. The upload finishes sending the data but remains hung in a wait state indefinitely. I am able to reproduce this very consistently. Below is a stack-trace when using 12.27.1

"main" #1 prio=5 os_prio=0 cpu=1490.57ms elapsed=496.37s tid=0x00007b4c0802c000 nid=0x2692e9 waiting on condition [0x00007b4c111f2000] java.lang.Thread.State: WAITING (parking) at jdk.internal.misc.Unsafe.park([email protected]/Native Method)

  • parking to wait for <0x00000004179dcf98> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject) at java.util.concurrent.locks.LockSupport.park([email protected]/LockSupport.java:194) at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await([email protected]/AbstractQueuedSynchronizer.java:2081) at com.azure.storage.blob.specialized.BlobOutputStream$BlockBlobOutputStream.commit(BlobOutputStream.java:268) at com.azure.storage.blob.specialized.BlobOutputStream.close(BlobOutputStream.java:136)
  • locked <0x00000004183173c0> (a com.azure.storage.blob.specialized.BlobOutputStream$BlockBlobOutputStream) at com.imanage.atlas.swift.UploadTest.run(UploadTest.java:55) at com.imanage.atlas.swift.UploadTest.main(UploadTest.java:25)

Here is the code for this example --

package com.demo.azure;

import com.azure.storage.blob.BlobClient;
import com.azure.storage.blob.BlobContainerClient;
import com.azure.storage.blob.BlobServiceClient;
import com.azure.storage.blob.BlobServiceClientBuilder;
import com.azure.storage.blob.models.ParallelTransferOptions;
import com.azure.storage.blob.options.BlockBlobOutputStreamOptions;
import com.azure.storage.blob.specialized.BlobOutputStream;

import java.io.File;
import java.io.FileInputStream;
import java.io.IOException;
import java.io.RandomAccessFile;

public class UploadTest {

    private static final String TEST_FILE_NAME = "test_file";
    private static final long TEST_FINAL_LENGTH = 367001600;

    public static void main(String[] args) {

        UploadTest test = new UploadTest();
        try{
            test.run();
        }catch(Throwable t){
            t.printStackTrace();
        }
    }

    public void run() throws IOException {

    File testFile = createFile(TEST_FILE_NAME, TEST_FINAL_LENGTH);
    BlobServiceClient blobServiceClient = new BlobServiceClientBuilder()
        .connectionString("DefaultEndpointsProtocol=https;AccountName=xxx;AccountKey=xxx==;EndpointSuffix=core.windows.net/")
        .buildClient();

    BlobContainerClient containerClient = blobServiceClient.getBlobContainerClient("1008-000000001");

    String blobName = "test" +  System.currentTimeMillis();
    BlobClient blobClient = containerClient.getBlobClient(blobName);

    BlockBlobOutputStreamOptions options = new BlockBlobOutputStreamOptions()
            .setParallelTransferOptions(new ParallelTransferOptions().setMaxSingleUploadSizeLong(33554432l));

    BlobOutputStream bos = blobClient.getBlockBlobClient().getBlobOutputStream(options);
    FileInputStream fis = new FileInputStream(testFile);
    byte[] buffer = new byte[320000];

    while(fis.available() >0){
        int read = fis.read(buffer);
        if (read > 0)
            bos.write(buffer, 0, read);
    }
    bos.close();
    System.out.println("Done");
}


    private File createFile(final String filename, final long sizeInBytes) throws IOException {
        File file = new File(filename);
        file.createNewFile();

        RandomAccessFile raf = new RandomAccessFile(file, "rw");
        raf.setLength(sizeInBytes);
        raf.close();

        return file;
    }


}

I have been running this from a location with 100MBPS internet access. If this is a race condition, the relatively slow network may be relevant.

Testing is on linux (pop os 24.04)

Describe the bug A clear and concise description of what the bug is.

Exception or Stack Trace Add the exception log and stack trace if available

To Reproduce Steps to reproduce the behavior:

Code Snippet Add the code snippet that causes the issue.

Expected behavior A clear and concise description of what you expected to happen.

Screenshots If applicable, add screenshots to help explain your problem.

Setup (please complete the following information):

  • OS: [e.g. iOS]
  • IDE: [e.g. IntelliJ]
  • Library/Libraries: [e.g. com.azure:azure-core:1.16.0 (groupId:artifactId:version)]
  • Java version: [e.g. 8]
  • App Server/Environment: [e.g. Tomcat, WildFly, Azure Function, Apache Spark, Databricks, IDE plugin or anything special]
  • Frameworks: [e.g. Spring Boot, Micronaut, Quarkus, etc]

If you suspect a dependency version mismatch (e.g. you see NoClassDefFoundError, NoSuchMethodError or similar), please check out Troubleshoot dependency version conflict article first. If it doesn't provide solution for the problem, please provide:

  • verbose dependency tree (mvn dependency:tree -Dverbose)
  • exception message, full stack trace, and any available logs

Additional context Add any other context about the problem here.

Information Checklist Kindly make sure that you have added all the following information above and checkoff the required fields otherwise we will treat the issuer as an incomplete report

  • [ ] Bug Description Added
  • [ ] Repro Steps Added
  • [ ] Setup information Added

vogeljd avatar Oct 07 '24 14:10 vogeljd

@ibrahimrabab @ibrandes @kyleknap @seanmcc-msft

github-actions[bot] avatar Oct 07 '24 14:10 github-actions[bot]

Thank you for your feedback. Tagging and routing to the team member best able to assist.

github-actions[bot] avatar Oct 07 '24 14:10 github-actions[bot]

Hi @vogeljd

I have tried reproducing this concurrency issue, but I don't see any issue with the code. its working perfectly fine for me. I've run the code about four times now, and each time, it successfully uploaded the blob to my container. here's the snapshot of it. Image

gunjansingh-msft avatar Oct 18 '24 13:10 gunjansingh-msft

Did you test with version 12.27.1 of the azure-storage-blob library?

On Fri, Oct 18, 2024 at 8:14 AM gunjansingh-msft @.***> wrote:

Hi @vogeljd https://github.com/vogeljd

I have tried reproducing this concurrency issue, but I don't see any issue with the code. its working perfectly fine for me. I've run the code about four times now, and each time, it successfully uploaded the blob to my container. here's the snapshot of it. Screenshot.2024-10-18.182806.png (view on web) https://github.com/user-attachments/assets/ac175338-5aed-4625-9224-ae1d1b3737d9

— Reply to this email directly, view it on GitHub https://github.com/Azure/azure-sdk-for-java/issues/42192#issuecomment-2422450995, or unsubscribe https://github.com/notifications/unsubscribe-auth/ABEAHLWL33FD3PXBSWWBAR3Z4ECRVAVCNFSM6AAAAABPQDGZRSVHI2DSMVQWIX3LMV43OSLTON2WKQ3PNVWWK3TUHMZDIMRSGQ2TAOJZGU . You are receiving this because you were mentioned.Message ID: @.***>

vogeljd avatar Oct 18 '24 13:10 vogeljd

Did you test with version 12.27.1 of the azure-storage-blob library? On Fri, Oct 18, 2024 at 8:14 AM gunjansingh-msft @.> wrote: Hi @vogeljd https://github.com/vogeljd I have tried reproducing this concurrency issue, but I don't see any issue with the code. its working perfectly fine for me. I've run the code about four times now, and each time, it successfully uploaded the blob to my container. here's the snapshot of it. Screenshot.2024-10-18.182806.png (view on web) https://github.com/user-attachments/assets/ac175338-5aed-4625-9224-ae1d1b3737d9 — Reply to this email directly, view it on GitHub <#42192 (comment)>, or unsubscribe https://github.com/notifications/unsubscribe-auth/ABEAHLWL33FD3PXBSWWBAR3Z4ECRVAVCNFSM6AAAAABPQDGZRSVHI2DSMVQWIX3LMV43OSLTON2WKQ3PNVWWK3TUHMZDIMRSGQ2TAOJZGU . You are receiving this because you were mentioned.Message ID: @.>

Yes, I have tested using the version 12.27.1 of the azure-storage-blob library.

gunjansingh-msft avatar Oct 22 '24 09:10 gunjansingh-msft

I found the issue, in my test harness the logging was breaking from a transitive dependency, which in turn masked another issue. Once I noticed and fixed the logging issue I saw the underlying issue, updating from 2.13.2-2 to 2.17.2 resolved the problem

Thanks

ang.LinkageError: Package versions: jackson-core=2.13.3, jackson-databind=2.13.2-2, jackson-dataformat-xml=2.17.2, jackson-datatype-jsr310=2.13.4, azure-core=1.52.0, Troubleshooting version conflicts: https://aka.ms/azsdk/java/dependency/troubleshoot at com.azure.core.implementation.jackson.ObjectMapperShim.writeValueAsBytes(ObjectMapperShim.java:191) at com.azure.core.util.serializer.JacksonAdapter.lambda$serializeToBytes$3(JacksonAdapter.java:213) at com.azure.core.util.serializer.JacksonAdapter.useAccessHelper(JacksonAdapter.java:491) at com.azure.core.util.serializer.JacksonAdapter.serializeToBytes(JacksonAdapter.java:209) at com.azure.core.implementation.http.rest.AsyncRestProxy.updateRequest(AsyncRestProxy.java:329) at com.azure.core.implementation.http.rest.RestProxyBase.configRequest(RestProxyBase.java:344) at com.azure.core.implementation.http.rest.RestProxyBase.createHttpRequest(RestProxyBase.java:291) at com.azure.core.implementation.http.rest.RestProxyBase.invoke(RestProxyBase.java:103) at com.azure.core.http.rest.RestProxy.invoke(RestProxy.java:92) at jdk.proxy2/jdk.proxy2.$Proxy10.commitBlockList(Unknown Source) at com.azure.storage.blob.implementation.BlockBlobsImpl.commitBlockListWithResponseAsync(BlockBlobsImpl.java:5207) at com.azure.storage.blob.specialized.BlockBlobAsyncClient.commitBlockListWithResponse(BlockBlobAsyncClient.java:1149) at com.azure.storage.blob.specialized.BlockBlobAsyncClient.lambda$commitBlockListWithResponse$11(BlockBlobAsyncClient.java:1134) at com.azure.core.util.FluxUtil.lambda$withContext$9(FluxUtil.java:406) at reactor.core.publisher.MonoDeferContextual.subscribe(MonoDeferContextual.java:47) at reactor.core.publisher.MonoFlatMap$FlatMapMain.onNext(MonoFlatMap.java:157) at reactor.core.publisher.Operators$MonoSubscriber.complete(Operators.java:1839) at reactor.core.publisher.MonoStreamCollector$StreamCollectorSubscriber.onComplete(MonoStreamCollector.java:178) at reactor.core.publisher.FluxMergeSequential$MergeSequentialMain.drain(FluxMergeSequential.java:374) at reactor.core.publisher.FluxMergeSequential$MergeSequentialMain.innerComplete(FluxMergeSequential.java:335) at reactor.core.publisher.FluxMergeSequential$MergeSequentialInner.onComplete(FluxMergeSequential.java:591) at reactor.core.publisher.FluxMapFuseable$MapFuseableSubscriber.onComplete(FluxMapFuseable.java:152) at reactor.core.publisher.FluxHide$SuppressFuseableSubscriber.onComplete(FluxHide.java:147) at reactor.core.publisher.Operators$MonoSubscriber.complete(Operators.java:1840) at reactor.core.publisher.MonoFlatMap$FlatMapInner.onNext(MonoFlatMap.java:249) at reactor.core.publisher.MonoIgnoreThen$ThenIgnoreMain.complete(MonoIgnoreThen.java:292) at reactor.core.publisher.MonoIgnoreThen$ThenIgnoreMain.onNext(MonoIgnoreThen.java:187) at reactor.core.publisher.MonoIgnoreThen$ThenIgnoreMain.subscribeNext(MonoIgnoreThen.java:236) at reactor.core.publisher.MonoIgnoreThen$ThenIgnoreMain.onComplete(MonoIgnoreThen.java:203) at reactor.core.publisher.MonoIgnoreElements$IgnoreElementsSubscriber.onComplete(MonoIgnoreElements.java:89) at reactor.core.publisher.Operators$MonoSubscriber.complete(Operators.java:1840) at reactor.core.publisher.FluxCallable.subscribe(FluxCallable.java:49) at reactor.core.publisher.Mono.subscribe(Mono.java:4491) at reactor.core.publisher.MonoIgnoreThen$ThenIgnoreMain.subscribeNext(MonoIgnoreThen.java:263) at reactor.core.publisher.MonoIgnoreThen.subscribe(MonoIgnoreThen.java:51) at reactor.core.publisher.MonoFlatMap$FlatMapMain.onNext(MonoFlatMap.java:157) at reactor.core.publisher.Operators$MonoSubscriber.complete(Operators.java:1839) at reactor.core.publisher.MonoFlatMap$FlatMapMain.onNext(MonoFlatMap.java:151) at reactor.core.publisher.FluxMapFuseable$MapFuseableSubscriber.onNext(FluxMapFuseable.java:129) at reactor.core.publisher.FluxHide$SuppressFuseableSubscriber.onNext(FluxHide.java:137) at reactor.core.publisher.FluxMapFuseable$MapFuseableSubscriber.onNext(FluxMapFuseable.java:129) at reactor.core.publisher.FluxHide$SuppressFuseableSubscriber.onNext(FluxHide.java:137) at reactor.core.publisher.FluxOnErrorResume$ResumeSubscriber.onNext(FluxOnErrorResume.java:79) at reactor.core.publisher.Operators$MonoSubscriber.complete(Operators.java:1839) at reactor.core.publisher.MonoFlatMap$FlatMapMain.onNext(MonoFlatMap.java:151) at reactor.core.publisher.FluxMapFuseable$MapFuseableSubscriber.onNext(FluxMapFuseable.java:129) at reactor.core.publisher.Operators$MonoSubscriber.complete(Operators.java:1839) at reactor.core.publisher.MonoFlatMap$FlatMapMain.onNext(MonoFlatMap.java:151) at reactor.core.publisher.FluxOnErrorResume$ResumeSubscriber.onNext(FluxOnErrorResume.java:79) at reactor.core.publisher.Operators$MonoSubscriber.complete(Operators.java:1839) at reactor.core.publisher.MonoFlatMap$FlatMapMain.onNext(MonoFlatMap.java:151) at reactor.core.publisher.Operators$MonoInnerProducerBase.complete(Operators.java:2666) at reactor.core.publisher.MonoSingle$SingleSubscriber.onComplete(MonoSingle.java:180) at reactor.core.publisher.MonoFlatMapMany$FlatMapManyInner.onComplete(MonoFlatMapMany.java:260) at reactor.core.publisher.FluxContextWrite$ContextWriteSubscriber.onComplete(FluxContextWrite.java:126) at reactor.core.publisher.MonoUsing$MonoUsingSubscriber.onNext(MonoUsing.java:232) at reactor.core.publisher.FluxMap$MapSubscriber.onNext(FluxMap.java:122) at reactor.core.publisher.FluxSwitchIfEmpty$SwitchIfEmptySubscriber.onNext(FluxSwitchIfEmpty.java:74) at reactor.core.publisher.Operators$ScalarSubscription.request(Operators.java:2400) at reactor.core.publisher.Operators$MultiSubscriptionSubscriber.set(Operators.java:2196) at reactor.core.publisher.Operators$MultiSubscriptionSubscriber.onSubscribe(Operators.java:2070) at reactor.core.publisher.MonoJust.subscribe(MonoJust.java:55) at reactor.core.publisher.Mono.subscribe(Mono.java:4491) at reactor.core.publisher.FluxSwitchIfEmpty$SwitchIfEmptySubscriber.onComplete(FluxSwitchIfEmpty.java:82) at reactor.core.publisher.FluxHandle$HandleSubscriber.onComplete(FluxHandle.java:220) at reactor.core.publisher.FluxMap$MapConditionalSubscriber.onComplete(FluxMap.java:275) at reactor.core.publisher.FluxDoFinally$DoFinallySubscriber.onComplete(FluxDoFinally.java:128) at reactor.core.publisher.FluxHandleFuseable$HandleFuseableSubscriber.onNext(FluxHandleFuseable.java:208) at reactor.core.publisher.FluxContextWrite$ContextWriteSubscriber.onNext(FluxContextWrite.java:107) at reactor.core.publisher.Operators$MonoSubscriber.complete(Operators.java:1839) at reactor.core.publisher.MonoCollectList$MonoCollectListSubscriber.onComplete(MonoCollectList.java:129) at reactor.core.publisher.FluxPeek$PeekSubscriber.onComplete(FluxPeek.java:260) at reactor.core.publisher.FluxMap$MapSubscriber.onComplete(FluxMap.java:144) at reactor.netty.channel.FluxReceive.onInboundComplete(FluxReceive.java:415) at reactor.netty.channel.ChannelOperations.onInboundComplete(ChannelOperations.java:439) at reactor.netty.channel.ChannelOperations.terminate(ChannelOperations.java:493) at reactor.netty.http.client.HttpClientOperations.onInboundNext(HttpClientOperations.java:789) at reactor.netty.channel.ChannelOperationsHandler.channelRead(ChannelOperationsHandler.java:114) at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:444) at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:420) at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:412) at com.azure.core.http.netty.implementation.AzureSdkHandler.channelRead(AzureSdkHandler.java:224) at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:442) at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:420) at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:412) at io.netty.channel.CombinedChannelDuplexHandler$DelegatingChannelHandlerContext.fireChannelRead(CombinedChannelDuplexHandler.java:436) at io.netty.handler.codec.ByteToMessageDecoder.fireChannelRead(ByteToMessageDecoder.java:346) at io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:318) at io.netty.channel.CombinedChannelDuplexHandler.channelRead(CombinedChannelDuplexHandler.java:251) at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:442) at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:420) at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:412) at io.netty.handler.ssl.SslHandler.unwrap(SslHandler.java:1475) at io.netty.handler.ssl.SslHandler.decodeNonJdkCompatible(SslHandler.java:1349) at io.netty.handler.ssl.SslHandler.decode(SslHandler.java:1389) at io.netty.handler.codec.ByteToMessageDecoder.decodeRemovalReentryProtection(ByteToMessageDecoder.java:530) at io.netty.handler.codec.ByteToMessageDecoder.callDecode(ByteToMessageDecoder.java:469) at io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:290) at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:444) at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:420) at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:412) at io.netty.channel.DefaultChannelPipeline$HeadContext.channelRead(DefaultChannelPipeline.java:1407) at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:440) at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:420) at io.netty.channel.DefaultChannelPipeline.fireChannelRead(DefaultChannelPipeline.java:918) at io.netty.channel.epoll.AbstractEpollStreamChannel$EpollStreamUnsafe.epollInReady(AbstractEpollStreamChannel.java:799) at io.netty.channel.epoll.EpollEventLoop.processReady(EpollEventLoop.java:501) at io.netty.channel.epoll.EpollEventLoop.run(EpollEventLoop.java:399) at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:994) at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74) at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30) at java.base/java.lang.Thread.run(Thread.java:1583)

On Tue, Oct 22, 2024 at 4:13 AM gunjansingh-msft @.***> wrote:

Did you test with version 12.27.1 of the azure-storage-blob library? … <#m_-1785657578868987421_> On Fri, Oct 18, 2024 at 8:14 AM gunjansingh-msft @.> wrote: Hi @vogeljd https://github.com/vogeljd https://github.com/vogeljd https://github.com/vogeljd I have tried reproducing this concurrency issue, but I don't see any issue with the code. its working perfectly fine for me. I've run the code about four times now, and each time, it successfully uploaded the blob to my container. here's the snapshot of it. Screenshot.2024-10-18.182806.png (view on web) https://github.com/user-attachments/assets/ac175338-5aed-4625-9224-ae1d1b3737d9 https://github.com/user-attachments/assets/ac175338-5aed-4625-9224-ae1d1b3737d9 — Reply to this email directly, view it on GitHub <#42192 (comment) https://github.com/Azure/azure-sdk-for-java/issues/42192#issuecomment-2422450995>, or unsubscribe https://github.com/notifications/unsubscribe-auth/ABEAHLWL33FD3PXBSWWBAR3Z4ECRVAVCNFSM6AAAAABPQDGZRSVHI2DSMVQWIX3LMV43OSLTON2WKQ3PNVWWK3TUHMZDIMRSGQ2TAOJZGU https://github.com/notifications/unsubscribe-auth/ABEAHLWL33FD3PXBSWWBAR3Z4ECRVAVCNFSM6AAAAABPQDGZRSVHI2DSMVQWIX3LMV43OSLTON2WKQ3PNVWWK3TUHMZDIMRSGQ2TAOJZGU . You are receiving this because you were mentioned.Message ID: @.>

Yes, I have tested using the version 12.27.1 of the azure-storage-blob library.

— Reply to this email directly, view it on GitHub https://github.com/Azure/azure-sdk-for-java/issues/42192#issuecomment-2428728631, or unsubscribe https://github.com/notifications/unsubscribe-auth/ABEAHLWNKII4FL3LGW6XR4TZ4YJNDAVCNFSM6AAAAABPQDGZRSVHI2DSMVQWIX3LMV43OSLTON2WKQ3PNVWWK3TUHMZDIMRYG4ZDQNRTGE . You are receiving this because you were mentioned.Message ID: @.***>

vogeljd avatar Oct 22 '24 17:10 vogeljd

@vogeljd seems like it's resolved for you now. So, marking this as close now.

gunjansingh-msft avatar Oct 23 '24 04:10 gunjansingh-msft