Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

aws-sdk+jruby: uploading 5mb+ files to minio (server/gateway) doesn't work #7120

Closed
shamil opened this issue Jan 18, 2019 · 19 comments
Closed

Comments

@shamil
Copy link
Contributor

shamil commented Jan 18, 2019

Expected Behavior

Uploading files over 5MB should work.

Current Behavior

  • doesn't work, the request stuck, until it fully times-out (see logs below)
  • doing same with mri ruby works!
  • doing same with other languages (e.g. python, go) works!
  • doing same, but upload directly to S3 instead of minio, also works!
  • uploading files less than 5MB works as well!

Steps to Reproduce (for bugs)

  1. Create a ruby script to upload 5mb+ file to minio (see below)
  2. Run the script with any 9+ jruby (I used one from docker images jruby:9.2 and jruby:9.1)
#!/usr/bin/env ruby
require 'aws-sdk-s3'

Aws.config.update(
    endpoint: 'http://localhost:9000',
    access_key_id: admin,
    secret_access_key: password,
    region: 'us-east-1',
    force_path_style: true,
    http_wire_trace: true
)

s3 = Aws::S3::Resource.new
obj = s3.bucket('mytestbucket').object('testobject_big')
obj.upload_file('/tmp/test.bin')

Your Environment

  • Tried several versions, same problem. Couldn't find one that working.
  • Tried minio server /mnt/minio, minio gateway nas /mnt/minio and minio gateway s3. Same problem!
  • Operating System and version (uname -a): 4.4.0-1057-aws

Logs files:

  • First snippet is small file (which is working)
  • Second snippet is ~13MB file (which is failing)
  • Third snippet is an error that I get from the above test script (aws-sdk HTTP trace logs)
PUT /mytestbucket/testobject_small
Host: 127.0.0.1:9000
X-Amz-Acl: private
Content-Md5: siV4/H7+XQuo9ftmyAGHug==
X-Amz-Content-Sha256: dd52aeb440590bac8a454ef86c2a02de4b2ff0cb9b0efc7ed301309b11e8940e
Content-Length: 2626
Content-Type: 
Accept-Encoding: 
User-Agent: aws-sdk-ruby2/2.11.207 jruby/2.3.3 java resources
Authorization: AWS4-HMAC-SHA256 Credential=admin/20190118/us-east-1/s3/aws4_request, SignedHeaders=content-md5;host;x-amz-acl;x-amz-content-sha256;x-amz-date;x-amz-storage-class, Signature=c7a7ac434ddb0490ab244f0a7b19d9b1556e1e92fe3384899a93bb0a883a50b7
Accept: */*
X-Amz-Storage-Class: STANDARD
Expect: 100-continue
X-Amz-Date: 20190118T211838Z

<BODY>

[RESPONSE] [154784631.873047] [2019-01-18 21:18:38 +0000]
200 OK
Content-Security-Policy: block-all-mixed-content
X-Amz-Request-Id: 157B0E06AAD26555
Etag: "b22578fc7efe5d0ba8f5fb66c80187ba"
Server: Minio/DEVELOPMENT.2019-01-18T17-49-05Z
Accept-Ranges: bytes
Vary: Origin
X-Xss-Protection: 1; mode=block

<BODY>
PUT /mytestbucket/testobject_big
Host: localhost:9000
User-Agent: aws-sdk-ruby2/2.11.207 jruby/2.3.3 java resources
X-Amz-Date: 20190118T211808Z
X-Amz-Content-Sha256: 25886cbbfeccdd3f65cd748b5dd2485276440ddbd5215adf733228d34f8d9722
Authorization: AWS4-HMAC-SHA256 Credential=admin/20190118/us-east-1/s3/aws4_request, SignedHeaders=content-md5;host;x-amz-content-sha256;x-amz-date, Signature=b12408b972dc4e7ea87fa7f10ba0885c6af844f27349ab82217d91c9faffce2c
Content-Length: 13571647
Accept: */*
Content-Type: 
Accept-Encoding: 
Expect: 100-continue
Content-Md5: nOVF8c2X3N0DfQKHp/FX7g==

<BODY>

[RESPONSE] [154784628.897485] [2019-01-18 21:19:09 +0000]
503 Service Unavailable
Vary: Origin
X-Xss-Protection: 1; mode=block
Content-Security-Policy: block-all-mixed-content
X-Amz-Request-Id: 157B0DFFBD3FF865
Server: Minio/DEVELOPMENT.2019-01-18T17-49-05Z
Accept-Ranges: bytes
Content-Type: application/xml

<?xml version="1.0" encoding="UTF-8"?>
<Error><Code>XMinioBackendDown</Code><Message>Object storage backend is unreachable</Message><Resource>/mytestbucket/testobject_big</Resource><RequestId>157B0DFFBD3FF865</RequestId><HostId>3L137</HostId></Error>
opening connection to localhost:9000...
opened
<- "PUT /mytestbucket/testobject_big HTTP/1.1\r\nContent-Type: \r\nAccept-Encoding: \r\nUser-Agent: aws-sdk-ruby2/2.11.207 jruby/2.3.3 java resources\r\nExpect: 100-continue\r\nContent-Md5: nOVF8c2X3N0DfQKHp/FX7g==\r\nX-Amz-Date: 20190118T211808Z\r\nHost: localhost:9000\r\nX-Amz-Content-Sha256: 25886cbbfeccdd3f65cd748b5dd2485276440ddbd5215adf733228d34f8d9722\r\nAuthorization: AWS4-HMAC-SHA256 Credential=admin/20190118/us-east-1/s3/aws4_request, SignedHeaders=content-md5;host;x-amz-content-sha256;x-amz-date, Signature=b12408b972dc4e7ea87fa7f10ba0885c6af844f27349ab82217d91c9faffce2c\r\nContent-Length: 13571647\r\nAccept: */*\r\n\r\n"
-> "HTTP/1.1 100 Continue\r\n"
-> "\r\n"
Conn close because of error Net::ReadTimeout
Conn close because of error Net::ReadTimeout
@kannappanr
Copy link
Contributor

@shamil XMinioBackendDown is probably returned only in the case of Gateway. Can we stick to say fs mode and capture the errors?

Also, can you try any other tool like mc or aws cli and try out the same file that fails?

@kannappanr kannappanr added this to the Next Release milestone Jan 19, 2019
@shamil
Copy link
Contributor Author

shamil commented Jan 19, 2019

hi @kannappanr,

Tried mc and s3cmd works well. It's just something to do with jruby.
Below are the errors when running minio in server mode (minio server /tmp/minio):

  1. First snippet is when client timeouts waiting for minio response
  2. Second snippet is when I increase timeout on client side to 5 minutes
400 Bad Request
Content-Security-Policy: block-all-mixed-content
X-Amz-Request-Id: 157B4BE7C2EA81DF
X-Minio-Deployment-Id: 30fe60c1-31d5-4640-a494-77d2c9992954
Server: Minio/RELEASE.2019-01-16T21-44-08Z
Accept-Ranges: bytes
Content-Type: application/xml
Vary: Origin
X-Xss-Protection: 1; mode=block

<?xml version="1.0" encoding="UTF-8"?>
<Error><Code>IncompleteBody</Code><Message>You did not provide the number of bytes specified by the Content-Length HTTP header.</Message><Resource>/mytestbucket/testobject_big</Resource><RequestId>157B4BE7C2EA81DF</RequestId><HostId>3L137</HostId></Error>
API: PutObject(bucket=mytestbucket, object=testobject_big)
Time: 16:21:21 UTC 01/19/2019
RequestID: 157B4C1C463257ED
RemoteHost: 127.0.0.1
UserAgent: aws-sdk-ruby2/2.11.207 jruby/2.3.3 java resources
Error: read tcp 127.0.0.1:9001->127.0.0.1:49814: i/o timeout
       1: cmd/fs-v1-helpers.go:349:cmd.fsCreateFile()
       2: cmd/fs-v1.go:910:cmd.(*FSObjects).putObject()
       3: cmd/fs-v1.go:818:cmd.(*FSObjects).PutObject()
       4: cmd/object-handlers.go:1159:cmd.ObjectLayer.PutObject-fm()
       5: cmd/object-handlers.go:1280:cmd.objectAPIHandlers.PutObjectHandler()
       6: cmd/api-router.go:77:cmd.objectAPIHandlers.PutObjectHandler-fm()
       7: pkg/handlers/http-tracer.go:144:handlers.TraceReqHandlerFunc.func1()
       8: net/http/server.go:1964:http.HandlerFunc.ServeHTTP()

500 Internal Server Error
Vary: Origin
X-Xss-Protection: 1; mode=block
Content-Security-Policy: block-all-mixed-content
X-Amz-Request-Id: 157B4C1C463257ED
X-Minio-Deployment-Id: 30fe60c1-31d5-4640-a494-77d2c9992954
Server: Minio/RELEASE.2019-01-16T21-44-08Z
Accept-Ranges: bytes
Content-Type: application/xml

<?xml version="1.0" encoding="UTF-8"?>
<Error><Code>InternalError</Code><Message>We encountered an internal error, please try again.</Message><Resource>/mytestbucket/testobject_big</Resource><RequestId>157B4C1C463257ED</RequestId><HostId>3L137</HostId></Error>

@kannappanr
Copy link
Contributor

@shamil I quickly did a search and found this link, can you try the suggestion provided in this link

https://stackoverflow.com/questions/17673174/aws-s3-gem-is-not-compatible-with-jruby

@shamil
Copy link
Contributor Author

shamil commented Jan 21, 2019

@kannappanr yes, tried that already, same problem.

Btw, problem doesn't persist if I upload to S3 directly (not via minio). The problem I experience occurs only when I use aws-sdk to upload to minio server. This is the reason I opened this issue here in the first place ...

@kannappanr
Copy link
Contributor

@shamil Thanks for the info. We will try to reproduce this issue. Can you please provide the version of minio that you are trying to use?

@shamil
Copy link
Contributor Author

shamil commented Jan 21, 2019

@kannappanr any version, in prod we run minio/minio:edge

@shamil
Copy link
Contributor Author

shamil commented Jan 21, 2019

@kannappanr one important thing. That sometimes its just work. So there is no 100% that it reproduce-able. I was able to reproduce that very often in our K8S cluster. So that might be related.

In any-case, do not invest your time on it too much, Ill try to narrow down the problem and maybe find the root, be it in minio or anything else.

Thanks for your time

@Praveenrajmani
Copy link
Contributor

Praveenrajmani commented Jan 22, 2019

@kannappanr @shamil I can see that go's standard http package behaves weirdly in our scenario with ruby sdk, The problem persists when the object's size is more than 7mb, The copy routine ( from the reader to the object temp file ) does not read more than 7mb ( 7 * 1024 * 1024 ) here in https://github.com/minio/minio/blob/8c1b649b2d70fd1ccbeaa14ada165d74d5d11da1/cmd/fs-v1-helpers.go#L346t (8mb objects are not chunked/uploaded in parts by aws s3 ruby sdk).

Looks like the 100-Continue mechanism is flaky in golang. For testing, i started two webservers one in go1.11.4 and the other in python3


import (
	"bytes"
	"fmt"
	"io"
	"log"
	"net/http"
)

func main() {

	http.HandleFunc("/myrubybucket/testobject_10mb", func(w http.ResponseWriter, r *http.Request) {

		var buff bytes.Buffer
		// This will be waiting indefinitely as it trying to read more than 7mb
		// `io.CopyN(&buff, r.Body, 7*1024*1024)` will work
		bytesW, e := io.CopyN(&buff, r.Body, r.ContentLength)
		if e != nil {
			fmt.Println(e)
		} else {
			fmt.Println(bytesW)
		}
		w.WriteHeader(200)
		w.Write([]byte("ping"))
	})

	log.Printf("listening on http://%s/", "192.168.86.163:9000")
	log.Fatal(http.ListenAndServe("192.168.86.163:9000", nil))
}

This will wait indefinitely if N is more than 7 * 1024 * 1024.

In Python, this seems to work well,

#from BaseHTTPServer import BaseHTTPRequestHandler,HTTPServer
from http.server import BaseHTTPRequestHandler, HTTPServer

PORT_NUMBER = 9000

class myHandler(BaseHTTPRequestHandler):
	
    def do_PUT(self):
            print("in post method")
            print(self.headers)
            self.handle_expect_100()
            
            data_string = self.rfile.read(int(self.headers["Content-Length"]))

            print(len(data_string))
            print(data_string.decode("utf-8"))
            
            self.send_response(200)
            self.end_headers()

            return
		

try:
        serverTuple = ('192.168.86.163', 9000)
        server = HTTPServer(serverTuple, myHandler)
        print('Started httpserver on port ' , PORT_NUMBER)
        server.serve_forever()

except KeyboardInterrupt:
        print('^C received, shutting down the web server')
        server.socket.close()

The ruby script

#!/usr/bin/env ruby
require 'aws-sdk-s3'

Aws.config.update(
    endpoint: 'http://192.168.86.163:9000',
    access_key_id: 'minio',
    secret_access_key: 'minio123',
    region: 'us-east-1',
    force_path_style: true,
    http_wire_trace: true
)

s3 = Aws::S3::Resource.new
obj = s3.bucket('myrubybucket').object('testobject_10mb')
obj.upload_file('10mb')

Let me see if there is a fix/work-around for this in golang.

@harshavardhana
Copy link
Member

100-Continue was buggy in boto upstream for which we submitted an upstream fix boto/botocore#1328

@shamil
Copy link
Contributor Author

shamil commented Jan 23, 2019

@harshavardhana not sure the problem relates to this case. We are talking about ruby sdk, not python.
@Praveenrajmani found some inappropriate behavior, maybe he has some fix in mind...

@harshavardhana
Copy link
Member

@shamil the point is both are written by AWS devs and in the past we have seen common issues across SDKs. We have discovered and fixed multiple issues upstream ranging from HTTP RFC compliance issues to incorrect signature SPEC implementation.

Go may not be a culprit here AFAICS, perhaps HTTP rfc implementation requirements misinterpreted by the client and here that is aws-sdk-ruby.

@Praveenrajmani
Copy link
Contributor

i got the same when tested in go1.10+ versions. I will raise an issue in the upstream library for this. As @harshavardhana mentioned. i'd better open the issue in both the upstreams.

@Praveenrajmani
Copy link
Contributor

Yet another work-around i could think of is uploading in parts with each part < 7mb. As per https://docs.aws.amazon.com/sdk-for-ruby/v3/api/Aws/S3/MultipartUploadPart.html#multipart_upload-instance_method

I can see

multipart_upload_part.upload({
  body: source_file,
  content_length: 1,
  content_md5: "ContentMD5",
  sse_customer_algorithm: "SSECustomerAlgorithm",
  sse_customer_key: "SSECustomerKey",
  sse_customer_key_md5: "SSECustomerKeyMD5",
  request_payer: "requester", # accepts requester
})

which can upload in chunks. with chunk size < 6~7mb. @shamil Shall we try this by manually chunking the object in parts of < 7mb each?

@harshavardhana
Copy link
Member

I am able to run it successfully

~  go run /tmp/main.go 
2019/01/23 12:27:44 listening on http://localhost:9000/
10485760
~ ruby /tmp/ruby.rb 
opening connection to localhost:9000...
opened
<- "PUT /myrubybucket/testobject_10mb HTTP/1.1\r\nContent-Type: \r\nAccept-Encoding: \r\nUser-Agent: aws-sdk-ruby3/3.46.0 ruby/2.5.1 x86_64-linux-gnu aws-sdk-s3/1.30.1\r\nExpect: 100-continue\r\nContent-Md5: 8clkXbwU793H2KMiaF8m6w==\r\nHost: localhost:9000\r\nX-Amz-Date: 20190123T202746Z\r\nX-Amz-Content-Sha256: e5b844cc57f57094ea4585e235f36c78c1cd222262bb89d53c94dcb4d6b3e55d\r\nAuthorization: AWS4-HMAC-SHA256 Credential=minio/20190123/us-east-1/s3/aws4_request, SignedHeaders=content-md5;expect;host;user-agent;x-amz-content-sha256;x-amz-date, Signature=c87e7ab64c499bd8342ceb6e729302d719d952cc7027a70c44e0473567b21ef5\r\nContent-Length: 10485760\r\nAccept: */*\r\n\r\n"
-> "HTTP/1.1 100 Continue\r\n"
-> "\r\n"
-> "HTTP/1.1 200 OK\r\n"
-> "Date: Wed, 23 Jan 2019 20:27:46 GMT\r\n"
-> "Content-Length: 4\r\n"
-> "Content-Type: text/plain; charset=utf-8\r\n"
-> "\r\n"
reading 4 bytes...
-> "ping"
read 4 bytes
Conn keep-alive

Ruby version is

~ ruby -v
ruby 2.5.1p57 (2018-03-29 revision 63029) [x86_64-linux-gnu]

@harshavardhana
Copy link
Member

Tested with minio server as well

~ ruby /tmp/ruby.rb 
opening connection to localhost:9000...
opened
<- "PUT /myrubybucket/testobject_10mb HTTP/1.1\r\nContent-Type: \r\nAccept-Encoding: \r\nUser-Agent: aws-sdk-ruby3/3.46.0 ruby/2.5.1 x86_64-linux-gnu aws-sdk-s3/1.30.1\r\nExpect: 100-continue\r\nContent-Md5: 8clkXbwU793H2KMiaF8m6w==\r\nHost: localhost:9000\r\nX-Amz-Date: 20190123T202953Z\r\nX-Amz-Content-Sha256: e5b844cc57f57094ea4585e235f36c78c1cd222262bb89d53c94dcb4d6b3e55d\r\nAuthorization: AWS4-HMAC-SHA256 Credential=minio/20190123/us-east-1/s3/aws4_request, SignedHeaders=content-md5;expect;host;user-agent;x-amz-content-sha256;x-amz-date, Signature=d15936a7c1a231a97675a867f65d0daf70836f6e31d938788772cccbdac6bcbe\r\nContent-Length: 10485760\r\nAccept: */*\r\n\r\n"
-> "HTTP/1.1 100 Continue\r\n"
-> "\r\n"
-> "HTTP/1.1 200 OK\r\n"
-> "Accept-Ranges: bytes\r\n"
-> "Content-Security-Policy: block-all-mixed-content\r\n"
-> "Etag: \"f1c9645dbc14efddc7d8a322685f26eb\"\r\n"
-> "Server: Minio/DEVELOPMENT.2019-01-23T19-33-38Z\r\n"
-> "Vary: Origin\r\n"
-> "X-Amz-Request-Id: 157C944459412D25\r\n"
-> "X-Amz-Server-Side-Encryption: AES256\r\n"
-> "X-Minio-Deployment-Id: 7564a643-0505-4c84-87fc-5095d5389967\r\n"
-> "X-Xss-Protection: 1; mode=block\r\n"
-> "Date: Wed, 23 Jan 2019 20:29:53 GMT\r\n"
-> "Content-Length: 0\r\n"
-> "\r\n"
reading 0 bytes...
-> ""
read 0 bytes
Conn keep-alive
~ mc ls myminio/myrubybucket/
[2019-01-23 12:29:53 PST]  10MiB testobject_10mb

@harshavardhana
Copy link
Member

I am also running the ruby script in a while true loop to reproduce this, but not able to.

@shamil
Copy link
Contributor Author

shamil commented Jan 23, 2019

@Praveenrajmani , @harshavardhana to put you guys in context.

  1. The problem I experience is with files bigger than 5MB
  2. For me it mostly happens with Jruby 9
  3. I don't control the code which does the S3 uploads, it's actually a logstash S3 plugin. So I don't own the code there. I can hard patch it, but I guess if I can avoid it this will be great

@Praveenrajmani your suggestion about multi-part upload works flawlessly!

This is how my test code looks like now:

#!/usr/bin/env ruby
require 'aws-sdk-s3'

Aws.config.update(
    endpoint: 'http://localhost:9000',
    access_key_id: admin,
    secret_access_key: password,
    region: 'us-east-1',
    force_path_style: true,
    http_wire_trace: true
)

s3 = Aws::S3::Resource.new
obj = s3.bucket('mytestbucket').object('testobject_big')
obj.upload_file('/tmp/test.bin', multipart_threshold: 4626070)

For now I will probably patch the logstash code, or submit them a PR to allow override default 15MB threshold...

Thanks guys for your help

@kannappanr
Copy link
Contributor

@shamil Closing this issue here. Please feel free to reach out to us if you have any other question.

@lock
Copy link

lock bot commented Apr 19, 2020

This thread has been automatically locked since there has not been any recent activity after it was closed. Please open a new issue for related bugs.

@lock lock bot locked as resolved and limited conversation to collaborators Apr 19, 2020
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Projects
None yet
Development

No branches or pull requests

4 participants