Error when s3 cp 4Gb file #413

limegreendender2 · 2024-02-22T13:24:53Z

limegreendender2
Feb 22, 2024

I'm looking at versitygw v0.14 to replace a minIO solution we are using in kubernetes.

When copying a 4GB tarball to posix host file system volume in a Kubernetes pod using metallb as the ingress/load-balancer I get the following error:

> time  aws --endpoint-url http://10.46.32.126 s3  cp s3-gw-14.392s-2024Q1.0_9.tar.gz  s3://s3gwtest
upload failed: ./s3-gw-14.392s-2024Q1.0_9.tar.gz to s3://s3gwtest/s3-gw-14.392s-2024Q1.0_9.tar.gz 
An error occurred (NoSuchUpload) when calling the CompleteMultipartUpload operation: 
The specified multipart upload does not exist. The upload ID may be invalid, or the upload may have been aborted or completed.

real    1m40.579s
user    0m26.173s
sys     0m11.048s

The file is transferred successfully and a .sgwtmp folder is left behind (occasionally with all the multipart files in it)

k8s yaml

apiVersion: apps/v1
kind: Deployment
metadata:
  name: s3-gateway
spec:
  selector:
    matchLabels:
      app: s3-gateway
  template:
    metadata:
      labels:
        app: s3-gateway   
    spec:
      containers:
      - name: s3-gateway
        image:  "local version of image built from your github Dockerfile"
        args: ["--debug" , "posix" , "/data"]
        env:
        - name: ROOT_ACCESS_KEY
          value: "foo"
        - name: ROOT_SECRET_KEY
          value: "bar"
        ports:
        - name: gateway
          containerPort: 7070 
        volumeMounts:
        - name: storage
          mountPath: /data
      nodeSelector:
        node-role: storage
      volumes:
      - name: storage
        hostPath:
          path: /u02/s3-xks
---
apiVersion: v1
kind: Service
metadata:
  name: s3-gateway-lb
  annotations:
    metallb.universe.tf/address-pool: default-pool
spec:
  loadBalancerIP: 10.46.32.126
  ports:
  - port: 80
    targetPort: 7070
  selector:
    app: s3-gateway
  type: LoadBalancer

The --debug log starts

No IAM service configured, enabling single account mode

 ┌───────────────────────────────────────────────────┐ 
 │                     versitygw                     │ 
 │                   Fiber v2.52.0                   │ 
 │               http://127.0.0.1:7070               │ 
 │       (bound on host 0.0.0.0 and port 7070)       │ 
 │                                                   │ 
 │ Handlers ............ 27  Processes ........... 1 │ 
 │ Prefork ....... Disabled  PID ................. 1 │ 
 └───────────────────────────────────────────────────┘ 

2024/02/22 12:59:33 Request headers: 
2024/02/22 12:59:33 Host: 10.46.32.126
2024/02/22 12:59:33 Content-Length: 0
2024/02/22 12:59:33 Content-Type: application/x-tar
2024/02/22 12:59:33 User-Agent: aws-cli/1.25.69 Python/3.7.11 Linux/3.10.0-1160.99.1.el7.x86_64 botocore/1.27.68
2024/02/22 12:59:33 Accept-Encoding: identity
2024/02/22 12:59:33 X-Amz-Date: 20240222T125934Z
2024/02/22 12:59:33 X-Amz-Content-Sha256: e3b0c44298fc1c149afbf4c8996fb92427ae41e4649b934ca495991b7852b855
2024/02/22 12:59:33 Authorization: AWS4-HMAC-SHA256 Credential=NTg5NjggICAgIDEK/20240222/us-east-1/s3/aws4_request, SignedHeaders=content-type;host;x-amz-content-sha256;x-amz-date, Signature=3485d78267c5e9df3cdd88927a0e43cd622c26222f9a70191100a325bb3edf70
2024/02/22 12:59:33 Amz-Sdk-Invocation-Id: ad93a350-5af4-44c6-9480-22a7063fe558
2024/02/22 12:59:33 Amz-Sdk-Request: attempt=1
2024/02/22 12:59:33 Request query arguments: 
2024/02/22 12:59:33 uploads: 

SDK 2024/02/22 12:59:33 DEBUG Request Signature:
---[ CANONICAL STRING  ]-----------------------------
POST
/s3gwtest/s3-gw-14.392s-2024Q1.0_9.tar.gz
uploads=
content-type:application/x-tar
host:10.46.32.126
x-amz-content-sha256:e3b0c44298fc1c149afbf4c8996fb92427ae41e4649b934ca495991b7852b855
x-amz-date:20240222T125934Z

content-type;host;x-amz-content-sha256;x-amz-date
e3b0c44298fc1c149afbf4c8996fb92427ae41e4649b934ca495991b7852b855
---[ STRING TO SIGN ]--------------------------------
AWS4-HMAC-SHA256
20240222T125934Z
20240222/us-east-1/s3/aws4_request
42af24629a4cb6f2cd27f45db7ce1a687def4ff727cd1ca13143cf38a662d642
-----------------------------------------------------
2024/02/22 12:59:33 Request Body: 
2024/02/22 12:59:33 Path parameters: 
2024/02/22 12:59:33 *1: 
2024/02/22 12:59:33 bucket: s3gwtest
2024/02/22 12:59:33 key: s3-gw-14.392s-2024Q1.0_9.tar.gz
2024/02/22 12:59:33 Response Headers: 
2024/02/22 12:59:33 Content-Length: 333
2024/02/22 12:59:33 Content-Type: application/xml
2024/02/22 12:59:33 Server: VERSITYGW
2024/02/22 12:59:33 Response body

And ends with

12:59:58 | 200 | 1m13.874746727s | 192.168.170.0 | POST | /s3gwtest/s3-gw-14.392s-2024Q1.0_9.tar.gz | -
2024/02/22 13:01:12 Request Body: <CompleteMultipartUpload xmlns="http://s3.amazonaws.com/doc/2006-03-01/">
<Part><ETag>f38514a92d886ccc4f1a1cda390eeea5</ETag><PartNumber>1</PartNumber></Part>
<Part><ETag>4622a8c522acc091b0e62171826951fc</ETag><PartNumber>2</PartNumber></Part>
<Part><ETag>c921dead586f95db053e2c80631f475f</ETag><PartNumber>3</PartNumber></Part>
<Part><ETag>9d66eec50bda3d6ba9b81519f7ffbfac</ETag><PartNumber>4</PartNumber></Part>
<Part><ETag>a911426f94555a684cfb35da71d43448</ETag><PartNumber>5</PartNumber></Part>
<Part><ETag>653696b968c01d6640165016675a4a36</ETag><PartNumber>6</PartNumber></Part>
<Part><ETag>c2d1192a09c373af7d6b01859216c23d</ETag><PartNumber>7</PartNumber></
.......
2024/02/22 13:01:12 Path parameters: 
2024/02/22 13:01:12 bucket: s3gwtest
2024/02/22 13:01:12 key: s3-gw-14.392s-2024Q1.0_9.tar.gz
2024/02/22 13:01:12 *1: 
2024/02/22 13:01:12 Response Headers: 
2024/02/22 13:01:12 Content-Length: 290
2024/02/22 13:01:12 Content-Type: application/xml
2024/02/22 13:01:12 Server: VERSITYGW
2024/02/22 13:01:12 Response body 
2024/02/22 13:01:12 Internal Error, open part 0xc0003285d8: open s3gwtest/.sgwtmp/multipart/8a22eeec0514081f10eefe62cf24c46ef9d2312e27e11d9966a2eb155320fbbf/93eb99c0-bda5-4c9c-9eaa-59837b7169d9/54: no such file or directory
13:00:58 | 500 | 13.909546197s | 192.168.170.0 | POST | /s3gwtest/s3-gw-14.392s-2024Q1.0_9.tar.gz | -

2024/02/22 13:01:13 Request headers: 
2024/02/22 13:01:13 Host: 10.46.32.126
2024/02/22 13:01:13 Content-Length: 42905
2024/02/22 13:01:13 User-Agent: aws-cli/1.25.69 Python/3.7.11 Linux/3.10.0-1160.99.1.el7.x86_64 botocore/1.27.68
2024/02/22 13:01:13 Accept-Encoding: identity
2024/02/22 13:01:13 X-Amz-Date: 20240222T130114Z
2024/02/22 13:01:13 X-Amz-Content-Sha256: 26b76e74b030acd1a9a6076c5128dd510a3e38de25750ece2e15c5afe3fc79eb
2024/02/22 13:01:13 Authorization: AWS4-HMAC-SHA256 Credential=NTg5NjggICAgIDEK/20240222/us-east-1/s3/aws4_request, SignedHeaders=host;x-amz-content-sha256;x-amz-date, Signature=255edd6bc02ee3b3d33a645bbb24df10fddb1f88b869d5215cb7b77cb100bfa5
2024/02/22 13:01:13 Amz-Sdk-Invocation-Id: e503bb9f-56f8-485b-9e72-8ba62f06920b
2024/02/22 13:01:13 Amz-Sdk-Request: ttl=20240222T130211Z; attempt=3; max=5
2024/02/22 13:01:13 Request query arguments: 
2024/02/22 13:01:13 uploadId: 93eb99c0-bda5-4c9c-9eaa-59837b7169d9
SDK 2024/02/22 13:01:13 DEBUG Request Signature:
---[ CANONICAL STRING  ]-----------------------------
POST
/s3gwtest/s3-gw-14.392s-2024Q1.0_9.tar.gz
uploadId=93eb99c0-bda5-4c9c-9eaa-59837b7169d9
host:10.46.32.126
x-amz-content-sha256:26b76e74b030acd1a9a6076c5128dd510a3e38de25750ece2e15c5afe3fc79eb
x-amz-date:20240222T130114Z

host;x-amz-content-sha256;x-amz-date
26b76e74b030acd1a9a6076c5128dd510a3e38de25750ece2e15c5afe3fc79eb
---[ STRING TO SIGN ]--------------------------------
AWS4-HMAC-SHA256
20240222T130114Z
20240222/us-east-1/s3/aws4_request
1cfbade8f55d7998ea5bf991b2c119384ec8fe137446cdadf1fa89fc0aa41cbd
-----------------------------------------------------
13:01:13 | 404 |    7.873228ms | 192.168.170.0 | POST | /s3gwtest/s3-gw-14.392s-2024Q1.0_9.tar.gz | -
2024/02/22 13:01:13 Request headers: 
2024/02/22 13:01:13 Host: 10.46.32.126
2024/02/22 13:01:13 Content-Length: 0
2024/02/22 13:01:13 User-Agent: aws-cli/1.25.69 Python/3.7.11 Linux/3.10.0-1160.99.1.el7.x86_64 botocore/1.27.68
2024/02/22 13:01:13 Accept-Encoding: identity
2024/02/22 13:01:13 X-Amz-Date: 20240222T130114Z

13:01:13 | 404 |     239.125µs | 192.168.170.0 | DELETE | /s3gwtest/s3-gw-14.392s-2024Q1.0_9.tar.gz | -
2024/02/22 13:01:13 X-Amz-Content-Sha256: e3b0c44298fc1c149afbf4c8996fb92427ae41e4649b934ca495991b7852b855
2024/02/22 13:01:13 Authorization: AWS4-HMAC-SHA256 Credential=NTg5NjggICAgIDEK/20240222/us-east-1/s3/aws4_request, SignedHeaders=host;x-amz-content-sha256;x-amz-date, Signature=3f0967ae587d0319395396a814c1595653a26ab9fdb0ae345f9b760cf3a8f780
2024/02/22 13:01:13 Amz-Sdk-Invocation-Id: ad6c082d-afd5-4f10-9984-c81fda35bad1
2024/02/22 13:01:13 Amz-Sdk-Request: attempt=1
2024/02/22 13:01:13 Request query arguments: 
2024/02/22 13:01:13 uploadId: 93eb99c0-bda5-4c9c-9eaa-59837b7169d9
SDK 2024/02/22 13:01:13 DEBUG Request Signature:
---[ CANONICAL STRING  ]-----------------------------
DELETE
/s3gwtest/s3-gw-14.392s-2024Q1.0_9.tar.gz
uploadId=93eb99c0-bda5-4c9c-9eaa-59837b7169d9
host:10.46.32.126
x-amz-content-sha256:e3b0c44298fc1c149afbf4c8996fb92427ae41e4649b934ca495991b7852b855
x-amz-date:20240222T130114Z

host;x-amz-content-sha256;x-amz-date
e3b0c44298fc1c149afbf4c8996fb92427ae41e4649b934ca495991b7852b855
---[ STRING TO SIGN ]--------------------------------
AWS4-HMAC-SHA256
20240222T130114Z
20240222/us-east-1/s3/aws4_request
415f5c3732055eb57e39b1492715ad9deb3274f4940d7ec3338c9e23ea663cb4
-----------------------------------------------------

Is there a configuration or option that I can use to prevent this error ?
Smaller files copy without issue.
Thanks
Alan

limegreendender2 · 2024-02-22T15:56:09Z

limegreendender2
Feb 22, 2024
Author

I think I can see what's happening when I use --debug at the client end.
At cp startup the time out is set to 60

2024-02-22 09:21:27,405 - MainThread - botocore.endpoint - DEBUG - Setting s3 timeout as (60, 60)

When versitygw server is reassembling the multipart files the client gets a read timeout.

2024-02-22 09:23:33,325 - ThreadPoolExecutor-0_3 - botocore.retryhandler - DEBUG - retry needed, retryable exception caught: Read timeout on endpoint URL: "http://10.46.32.126/s3gwtest/minio-15.583-2024Q1.0_9.tar.gz?uploadId=9a40b098-0595-46b4-9af8-8a4f39559770"
Traceback (most recent call last):
  File "/usr/local/aws-cli/lib/python3.7/site-packages/urllib3/connectionpool.py", line 449, in _make_request
    six.raise_from(e, None)
  File "<string>", line 3, in raise_from
  File "/usr/local/aws-cli/lib/python3.7/site-packages/urllib3/connectionpool.py", line 444, in _make_request
    httplib_response = conn.getresponse()
  File "/opt/python3.7.11/lib/python3.7/http/client.py", line 1373, in getresponse
    response.begin()
  File "/opt/python3.7.11/lib/python3.7/http/client.py", line 319, in begin
    version, status, reason = self._read_status()
  File "/opt/python3.7.11/lib/python3.7/http/client.py", line 280, in _read_status
    line = str(self.fp.readline(_MAXLINE + 1), "iso-8859-1")
  File "/opt/python3.7.11/lib/python3.7/socket.py", line 589, in readinto
    return self._sock.recv_into(b)
socket.timeout: timed out

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/local/aws-cli/lib/python3.7/site-packages/botocore/httpsession.py", line 457, in send
    chunked=self._chunked(request.headers),
  File "/usr/local/aws-cli/lib/python3.7/site-packages/urllib3/connectionpool.py", line 788, in urlopen
    method, url, error=e, _pool=self, _stacktrace=sys.exc_info()[2]
  File "/usr/local/aws-cli/lib/python3.7/site-packages/urllib3/util/retry.py", line 525, in increment
    raise six.reraise(type(error), error, _stacktrace)
  File "/usr/local/aws-cli/lib/python3.7/site-packages/urllib3/packages/six.py", line 770, in reraise
    raise value
  File "/usr/local/aws-cli/lib/python3.7/site-packages/urllib3/connectionpool.py", line 710, in urlopen
    chunked=chunked,
  File "/usr/local/aws-cli/lib/python3.7/site-packages/urllib3/connectionpool.py", line 451, in _make_request
    self._raise_timeout(err=e, url=url, timeout_value=read_timeout)
  File "/usr/local/aws-cli/lib/python3.7/site-packages/urllib3/connectionpool.py", line 341, in _raise_timeout
    self, url, "Read timed out. (read timeout=%s)" % timeout_value
urllib3.exceptions.ReadTimeoutError: AWSHTTPConnectionPool(host='10.46.32.126', port=80): Read timed out. (read timeout=60)

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/local/aws-cli/lib/python3.7/site-packages/botocore/retryhandler.py", line 308, in _should_retry
    attempt_number, response, caught_exception
  File "/usr/local/aws-cli/lib/python3.7/site-packages/botocore/retryhandler.py", line 364, in __call__
    attempt_number, response, caught_exception
  File "/usr/local/aws-cli/lib/python3.7/site-packages/botocore/retryhandler.py", line 248, in __call__
    attempt_number, caught_exception
  File "/usr/local/aws-cli/lib/python3.7/site-packages/botocore/retryhandler.py", line 416, in _check_caught_exception
    raise caught_exception
  File "/usr/local/aws-cli/lib/python3.7/site-packages/botocore/endpoint.py", line 281, in _do_get_response
    http_response = self._send(request)
  File "/usr/local/aws-cli/lib/python3.7/site-packages/botocore/endpoint.py", line 377, in _send
    return self.http_session.send(request)
  File "/usr/local/aws-cli/lib/python3.7/site-packages/botocore/httpsession.py", line 485, in send
    raise ReadTimeoutError(endpoint_url=request.url, error=e)
botocore.exceptions.ReadTimeoutError: Read timeout on endpoint URL: "http://10.46.32.126/s3gwtest/minio-15.583-2024Q1.0_9.tar.gz?uploadId=
9a40b098-0595-46b4-9af8-8a4f39559770"

When I raise the timeout to 10 minutes the cp doesn't raise error

time  aws --cli-read-timeout 600  --endpoint-url http://10.46.32.126 s3  cp minio-15.583-2024Q1.0_9.tar.gz  s3://s3gwtest

Would it be possible for the server to send some keep-alive signal back to the client while reassembling the file?

BTW minIO with the same aws s3 cp command does not timeout.

0 replies

benmcclelland · 2024-02-29T05:11:53Z

benmcclelland
Feb 29, 2024
Maintainer

@limegreendender2 This is the error for the first issue above:

2024/02/22 13:01:12 Internal Error, open part 0xc0003285d8: open s3gwtest/.sgwtmp/multipart/8a22eeec0514081f10eefe62cf24c46ef9d2312e27e11d9966a2eb155320fbbf/93eb99c0-bda5-4c9c-9eaa-59837b7169d9/54: no such file or directory

means that the gateway did not find the files that it expected for this mutlipart upload. The in progress multipart uploads are stored in .sgwmp/multipart. The first part of that is the sha256 of the object name:

$ echo -n "s3-gw-14.392s-2024Q1.0_9.tar.gz" | sha256sum 
8a22eeec0514081f10eefe62cf24c46ef9d2312e27e11d9966a2eb155320fbbf  -

The next part: 93eb99c0-bda5-4c9c-9eaa-59837b7169d9 is a uuid for a unique uploadid for this upload.
And the files below this are the part numbers.

I'll need to check, but it looks like we might be returning the wrong error in this case. For this one it looks like part 54 was not successfully uploaded here. I'm guessing this is related to your last update where commands are timing out. We can look into adding keepalives here. I'll open an issue for this.

0 replies

benmcclelland · 2024-02-29T05:15:38Z

benmcclelland
Feb 29, 2024
Maintainer

Maybe another thing to note here is that if the /data backend could be a filesystem that supports copy_file_range(), then the reassembly should go significantly faster. If not supported, then the gateway falls back to just copying all the data between the part files and the final object file.

1 reply

limegreendender2 Feb 29, 2024
Author

Thanks for this. It has highlighted that the node I'm using missed out on our el8 upgrade. Still on 3.10.0-1160.102.1.el7.x86_64
copy_file_range system call didn't appear until Linux kernel 4.5. EL8 upgrade requested.

benmcclelland · 2024-02-29T05:20:20Z

benmcclelland
Feb 29, 2024
Maintainer

tracking this in issue #423

0 replies

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Error when s3 cp 4Gb file #413

{{title}}

Replies: 4 comments 1 reply

{{title}}

{{title}}

{{title}}

{{title}}

{{title}}

Select a reply

Error when s3 cp 4Gb file #413

limegreendender2 Feb 22, 2024

Replies: 4 comments · 1 reply

limegreendender2 Feb 22, 2024 Author

benmcclelland Feb 29, 2024 Maintainer

benmcclelland Feb 29, 2024 Maintainer

limegreendender2 Feb 29, 2024 Author

benmcclelland Feb 29, 2024 Maintainer

limegreendender2
Feb 22, 2024

Replies: 4 comments 1 reply

limegreendender2
Feb 22, 2024
Author

benmcclelland
Feb 29, 2024
Maintainer

benmcclelland
Feb 29, 2024
Maintainer

limegreendender2 Feb 29, 2024
Author

benmcclelland
Feb 29, 2024
Maintainer