s3proxy icon indicating copy to clipboard operation
s3proxy copied to clipboard
verified publisher icon gaul

question: An error occurred storing the new blob with name

Open cstmgl opened this issue 3 years ago • 1 comments

Hi all, I must start by saying I just discovered this project a couple of days ago and I'm really happy with it because it really provides what I was looking for, a tool that helps me with my unit-testing for APIs using S3.

However I have a weird behavior that I'm not sure how to explain or what might be the reason, so wondering if anyone experienced this and can give me some pointers. Basically for some of my colleagues using S3 Proxy does not work for them (we use it in windows just by launching the jar). For me (also in windows) it works perfectly fine. Also in Jenkins it works perfectly fine (in linux).

Anyway by looking at the logs in the S3 Proxy I see this:

19:40:48.371 [S3Proxy-Jetty-17] DEBUG org.gaul.shaded.org.eclipse.jetty.server.HttpChannel - REQUEST for //localhost:9999/testbucket/testFile_1651772445350.txt?uploads on HttpChannelOverHttp@48a4c841{s=HttpChannelState@1cd52eda{s=IDLE rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0},r=1,c=false/false,a=IDLE,uri=//localhost:9999/testbucket/testFile_1651772445350.txt?uploads,age=0}
POST //localhost:9999/testbucket/testFile_1651772445350.txt?uploads HTTP/1.1
Host: localhost:9999
amz-sdk-invocation-id: 13c49701-2d75-dff7-3e52-a1f90429bb3a
amz-sdk-request: attempt=1;max=2
amz-sdk-retry: 0/0/500
Authorization: AWS4-HMAC-SHA256 Credential=s3test/20220505/eu-west-1/s3/aws4_request, SignedHeaders=amz-sdk-invocation-id;amz-sdk-request;amz-sdk-retry;content-length;content-type;host;user-agent;x-amz-content-sha256;x-amz-date, Signature=f15484a815bd4de05fedd9699ac2dac3d175b8ec053939fdf8226ae470ced507
Content-Type: application/octet-stream
User-Agent: APN/1.0 Confluent/1.0 KafkaS3Connector/10.0.3, aws-sdk-java/1.12.205 Windows_10/10.0 OpenJDK_64-Bit_Server_VM/11.0.12+7 java/11.0.12 vendor/Eclipse_Foundation cfg/retry-mode/legacy
x-amz-content-sha256: e3b0c44298fc1c149afbf4c8996fb92427ae41e4649b934ca495991b7852b855
X-Amz-Date: 20220505T174048Z
Content-Length: 0
Connection: Keep-Alive


19:40:48.371 [S3Proxy-Jetty-17] DEBUG org.gaul.shaded.org.eclipse.jetty.server.HttpConnection - HttpConnection@36542d66::SocketChannelEndPoint@4e1e05c3{l=/127.0.0.1:9999,r=/127.0.0.1:61341,OPEN,fill=-,flush=-,to=3/30000}{io=0/0,kio=0,kro=1}->HttpConnection@36542d66[p=HttpParser{s=CONTENT,0 of 0},g=HttpGenerator@665221f8{s=START}]=>HttpChannelOverHttp@48a4c841{s=HttpChannelState@1cd52eda{s=IDLE rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0},r=1,c=false/false,a=IDLE,uri=//localhost:9999/testbucket/testFile_1651772445350.txt?uploads,age=0} parsed true HttpParser{s=CONTENT,0 of 0}
19:40:48.372 [S3Proxy-Jetty-17] DEBUG org.gaul.shaded.org.eclipse.jetty.server.HttpConnection - releaseRequestBuffer HttpConnection@36542d66::SocketChannelEndPoint@4e1e05c3{l=/127.0.0.1:9999,r=/127.0.0.1:61341,OPEN,fill=-,flush=-,to=3/30000}{io=0/0,kio=0,kro=1}->HttpConnection@36542d66[p=HttpParser{s=CONTENT,0 of 0},g=HttpGenerator@665221f8{s=START}]=>HttpChannelOverHttp@48a4c841{s=HttpChannelState@1cd52eda{s=IDLE rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0},r=1,c=false/false,a=IDLE,uri=//localhost:9999/testbucket/testFile_1651772445350.txt?uploads,age=1}
19:40:48.372 [S3Proxy-Jetty-17] DEBUG org.gaul.shaded.org.eclipse.jetty.server.HttpChannel - handle //localhost:9999/testbucket/testFile_1651772445350.txt?uploads HttpChannelOverHttp@48a4c841{s=HttpChannelState@1cd52eda{s=IDLE rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0},r=1,c=false/false,a=IDLE,uri=//localhost:9999/testbucket/testFile_1651772445350.txt?uploads,age=1} 
19:40:48.372 [S3Proxy-Jetty-17] DEBUG org.gaul.shaded.org.eclipse.jetty.server.HttpChannelState - handling HttpChannelState@1cd52eda{s=IDLE rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0}
19:40:48.372 [S3Proxy-Jetty-17] DEBUG org.gaul.shaded.org.eclipse.jetty.server.HttpChannel - action DISPATCH HttpChannelOverHttp@48a4c841{s=HttpChannelState@1cd52eda{s=HANDLING rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0},r=1,c=false/false,a=HANDLING,uri=//localhost:9999/testbucket/testFile_1651772445350.txt?uploads,age=1}
19:40:48.372 [S3Proxy-Jetty-17] DEBUG org.gaul.shaded.org.eclipse.jetty.server.Server - REQUEST POST /testbucket/testFile_1651772445350.txt on HttpChannelOverHttp@48a4c841{s=HttpChannelState@1cd52eda{s=HANDLING rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0},r=1,c=false/false,a=HANDLING,uri=//localhost:9999/testbucket/testFile_1651772445350.txt?uploads,age=1}
19:40:48.372 [S3Proxy-Jetty-17] DEBUG org.gaul.s3proxy.S3ProxyHandler - request: Request(POST //localhost:9999/testbucket/testFile_1651772445350.txt?uploads)@5f371be9
19:40:48.372 [S3Proxy-Jetty-17] DEBUG org.gaul.s3proxy.S3ProxyHandler - header: Authorization: AWS4-HMAC-SHA256 Credential=s3test/20220505/eu-west-1/s3/aws4_request, SignedHeaders=amz-sdk-invocation-id;amz-sdk-request;amz-sdk-retry;content-length;content-type;host;user-agent;x-amz-content-sha256;x-amz-date, Signature=f15484a815bd4de05fedd9699ac2dac3d175b8ec053939fdf8226ae470ced507
19:40:48.372 [S3Proxy-Jetty-17] DEBUG org.gaul.s3proxy.S3ProxyHandler - header: x-amz-content-sha256: e3b0c44298fc1c149afbf4c8996fb92427ae41e4649b934ca495991b7852b855
19:40:48.372 [S3Proxy-Jetty-17] DEBUG org.gaul.s3proxy.S3ProxyHandler - header: X-Amz-Date: 20220505T174048Z
19:40:48.372 [S3Proxy-Jetty-17] DEBUG org.gaul.s3proxy.S3ProxyHandler - header: User-Agent: APN/1.0 Confluent/1.0 KafkaS3Connector/10.0.3, aws-sdk-java/1.12.205 Windows_10/10.0 OpenJDK_64-Bit_Server_VM/11.0.12+7 java/11.0.12 vendor/Eclipse_Foundation cfg/retry-mode/legacy
19:40:48.372 [S3Proxy-Jetty-17] DEBUG org.gaul.s3proxy.S3ProxyHandler - header: Connection: Keep-Alive
19:40:48.372 [S3Proxy-Jetty-17] DEBUG org.gaul.s3proxy.S3ProxyHandler - header: Host: localhost:9999
19:40:48.372 [S3Proxy-Jetty-17] DEBUG org.gaul.s3proxy.S3ProxyHandler - header: amz-sdk-invocation-id: 13c49701-2d75-dff7-3e52-a1f90429bb3a
19:40:48.372 [S3Proxy-Jetty-17] DEBUG org.gaul.s3proxy.S3ProxyHandler - header: amz-sdk-request: attempt=1;max=2
19:40:48.372 [S3Proxy-Jetty-17] DEBUG org.gaul.s3proxy.S3ProxyHandler - header: amz-sdk-retry: 0/0/500
19:40:48.372 [S3Proxy-Jetty-17] DEBUG org.gaul.s3proxy.S3ProxyHandler - header: Content-Length: 0
19:40:48.372 [S3Proxy-Jetty-17] DEBUG org.gaul.s3proxy.S3ProxyHandler - header: Content-Type: application/octet-stream
19:40:48.384 [S3Proxy-Jetty-17] DEBUG org.jclouds.blobstore.config.LocalBlobStore - Put blob with key [.mpus-9c08d428-7b90-460b-971c-f570c16df0fd-testFile_1651772445350.txt-stub] to container [testbucket]
19:40:48.394 [S3Proxy-Jetty-17] DEBUG org.jclouds.filesystem.strategy.internal.FilesystemStorageStrategyImpl - xattrs not supported on build\s3proxy\buckets\testbucket\.mpus-9c08d428-7b90-460b-971c-f570c16df0fd-testFile_1651772445350.txt-stub-44c41bee-7b3d-4f46-bca0-27523c9e4274
19:40:48.402 [S3Proxy-Jetty-17] ERROR org.jclouds.blobstore.config.LocalBlobStore - An error occurred storing the new blob with name [.mpus-9c08d428-7b90-460b-971c-f570c16df0fd-testFile_1651772445350.txt-stub] to container [testbucket].
java.io.IOException: Could not rename file build\s3proxy\buckets\testbucket\.mpus-9c08d428-7b90-460b-971c-f570c16df0fd-testFile_1651772445350.txt-stub-44c41bee-7b3d-4f46-bca0-27523c9e4274 to build\s3proxy\buckets\testbucket\.mpus-9c08d428-7b90-460b-971c-f570c16df0fd-testFile_1651772445350.txt-stub
	at org.jclouds.filesystem.strategy.internal.FilesystemStorageStrategyImpl.putBlob(FilesystemStorageStrategyImpl.java:594)
	at org.jclouds.blobstore.config.LocalBlobStore.putBlob(LocalBlobStore.java:795)
	at org.jclouds.blobstore.config.LocalBlobStore.putBlob(LocalBlobStore.java:533)
	at org.jclouds.blobstore.config.LocalBlobStore.initiateMultipartUpload(LocalBlobStore.java:820)
	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
	at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.base/java.lang.reflect.Method.invoke(Method.java:566)
	at com.google.inject.internal.DelegatingInvocationHandler.invoke(DelegatingInvocationHandler.java:50)
	at com.sun.proxy.$Proxy50.initiateMultipartUpload(Unknown Source)
	at org.gaul.s3proxy.S3ProxyHandler.handleInitiateMultipartUpload(S3ProxyHandler.java:2190)
	at org.gaul.s3proxy.S3ProxyHandler.doHandle(S3ProxyHandler.java:720)
	at org.gaul.s3proxy.S3ProxyHandlerJetty.handle(S3ProxyHandlerJetty.java:77)
	at org.gaul.shaded.org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:127)
	at org.gaul.shaded.org.eclipse.jetty.server.Server.handle(Server.java:516)
	at org.gaul.shaded.org.eclipse.jetty.server.HttpChannel.lambda$handle$1(HttpChannel.java:487)
	at org.gaul.shaded.org.eclipse.jetty.server.HttpChannel.dispatch(HttpChannel.java:732)
	at org.gaul.shaded.org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:479)
	at org.gaul.shaded.org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:277)
	at org.gaul.shaded.org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:311)
	at org.gaul.shaded.org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:105)
	at org.gaul.shaded.org.eclipse.jetty.io.ChannelEndPoint$1.run(ChannelEndPoint.java:104)
	at org.gaul.shaded.org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.runTask(EatWhatYouKill.java:338)
	at org.gaul.shaded.org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.doProduce(EatWhatYouKill.java:315)
	at org.gaul.shaded.org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.tryProduce(EatWhatYouKill.java:173)
	at org.gaul.shaded.org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.produce(EatWhatYouKill.java:137)
	at org.gaul.shaded.org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:883)
	at org.gaul.shaded.org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.run(QueuedThreadPool.java:1034)
	at java.base/java.lang.Thread.run(Thread.java:829)
19:40:48.406 [S3Proxy-Jetty-17] DEBUG org.gaul.s3proxy.S3ProxyHandlerJetty - Unknown exception:
java.lang.RuntimeException: java.io.IOException: Could not rename file build\s3proxy\buckets\testbucket\.mpus-9c08d428-7b90-460b-971c-f570c16df0fd-testFile_1651772445350.txt-stub-44c41bee-7b3d-4f46-bca0-27523c9e4274 to build\s3proxy\buckets\testbucket\.mpus-9c08d428-7b90-460b-971c-f570c16df0fd-testFile_1651772445350.txt-stub
	at com.google.common.base.Throwables.propagate(Throwables.java:241)
	at org.jclouds.blobstore.config.LocalBlobStore.putBlob(LocalBlobStore.java:806)
	at org.jclouds.blobstore.config.LocalBlobStore.putBlob(LocalBlobStore.java:533)
	at org.jclouds.blobstore.config.LocalBlobStore.initiateMultipartUpload(LocalBlobStore.java:820)
	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
	at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.base/java.lang.reflect.Method.invoke(Method.java:566)
	at com.google.inject.internal.DelegatingInvocationHandler.invoke(DelegatingInvocationHandler.java:50)
	at com.sun.proxy.$Proxy50.initiateMultipartUpload(Unknown Source)
	at org.gaul.s3proxy.S3ProxyHandler.handleInitiateMultipartUpload(S3ProxyHandler.java:2190)
	at org.gaul.s3proxy.S3ProxyHandler.doHandle(S3ProxyHandler.java:720)
	at org.gaul.s3proxy.S3ProxyHandlerJetty.handle(S3ProxyHandlerJetty.java:77)
	at org.gaul.shaded.org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:127)
	at org.gaul.shaded.org.eclipse.jetty.server.Server.handle(Server.java:516)
	at org.gaul.shaded.org.eclipse.jetty.server.HttpChannel.lambda$handle$1(HttpChannel.java:487)
	at org.gaul.shaded.org.eclipse.jetty.server.HttpChannel.dispatch(HttpChannel.java:732)
	at org.gaul.shaded.org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:479)
	at org.gaul.shaded.org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:277)
	at org.gaul.shaded.org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:311)
	at org.gaul.shaded.org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:105)
	at org.gaul.shaded.org.eclipse.jetty.io.ChannelEndPoint$1.run(ChannelEndPoint.java:104)
	at org.gaul.shaded.org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.runTask(EatWhatYouKill.java:338)
	at org.gaul.shaded.org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.doProduce(EatWhatYouKill.java:315)
	at org.gaul.shaded.org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.tryProduce(EatWhatYouKill.java:173)
	at org.gaul.shaded.org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.produce(EatWhatYouKill.java:137)
	at org.gaul.shaded.org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:883)
	at org.gaul.shaded.org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.run(QueuedThreadPool.java:1034)
	at java.base/java.lang.Thread.run(Thread.java:829)
Caused by: java.io.IOException: Could not rename file build\s3proxy\buckets\testbucket\.mpus-9c08d428-7b90-460b-971c-f570c16df0fd-testFile_1651772445350.txt-stub-44c41bee-7b3d-4f46-bca0-27523c9e4274 to build\s3proxy\buckets\testbucket\.mpus-9c08d428-7b90-460b-971c-f570c16df0fd-testFile_1651772445350.txt-stub
	at org.jclouds.filesystem.strategy.internal.FilesystemStorageStrategyImpl.putBlob(FilesystemStorageStrategyImpl.java:594)
	at org.jclouds.blobstore.config.LocalBlobStore.putBlob(LocalBlobStore.java:795)
	... 27 common frames omitted

I noticed somehow it's trying to create a weird file (I guess because of multi-part upload). Can someone give me some pointers of what might be the reason?

This is my s3proxy configuration

s3proxy.authorization=none
s3proxy.endpoint=http://127.0.0.1:9999
jclouds.provider=filesystem
jclouds.filesystem.basedir=build/s3proxy/buckets

Thank you for any feedback and best regards,

cstmgl avatar May 06 '22 09:05 cstmgl

It seems like there is an unexpected stub file, possibly from an incomplete or concurrent operation? But I believe that File.renameTo does not replace the file on Windows. It looks like Files.move with the correct flag might help. Could you try this and submit a PR if it helps?

gaul avatar Jun 29 '22 02:06 gaul