Issues with aws s3 sse-c, getting strange log entries and errors

asdffdsa · November 18, 2020, 10:17pm

What is the problem you are having with rclone?

trying to copy a single file of size 1 byte
yet this is the log output

Transferred:   	         3 / 3 Bytes, 100%, 5 Bytes/s, ETA 0s
Errors:                 1 (retrying may help)
Checks:                 2 / 2, 100%

What is your rclone version (output from `rclone version`)

rclone v1.53.2
- os/arch: windows/amd64
- go version: go1.15.2

Which OS you are using and how many bits (eg Windows 7, 64 bit)

win10.2004.64bit

Which cloud storage system are you using? (eg Google Drive)

aws s3

The command you were trying to run (eg `rclone copy /tmp remote:tmp`)

rclone copy C:\ex\wg\test awsssectest:a1b2c3d44d3c2b1a --s3-sse-customer-algorithm=AES256 --s3-sse-customer-key="czn8qrbUsT/5y5Hr2i93ImWmIQLCZLOL" --s3-sse-customer-key-md5="ME4ss65LcXQBY2CynVdZyA==" --log-file=log.ssec.txt --log-level=DEBUG

The rclone config contents with secrets removed.

[awsssectest]
type = s3
provider = AWS
access_key_id = 
secret_access_key = 
storage_class = STANDARD

A log from the command with the `-vv` flag

2020/11/18 17:10:57 DEBUG : rclone: Version "v1.53.2" starting with parameters ["c:\\data\\rclone\\scripts\\rclone.exe" "copy" "C:\\ex\\wg\\test" "awsssectest:a1b2c3d44d3c2b1a" "--s3-sse-customer-algorithm=AES256" "--s3-sse-customer-key=czn8qrbUsT/5y5Hr2i93ImWmIQLCZLOL" "--s3-sse-customer-key-md5=ME4ss65LcXQBY2CynVdZyA==" "--log-file=log.ssec.txt" "--log-level=DEBUG"]
2020/11/18 17:10:57 DEBUG : Creating backend with remote "C:\\ex\\wg\\test"
2020/11/18 17:10:57 DEBUG : Using RCLONE_CONFIG_PASS password.
2020/11/18 17:10:57 DEBUG : Using config file from "c:\\data\\rclone\\scripts\\rclone.conf"
2020/11/18 17:10:57 DEBUG : fs cache: renaming cache item "C:\\ex\\wg\\test" to be canonical "//?/C:/ex/wg/test"
2020/11/18 17:10:57 DEBUG : Creating backend with remote "awsssectest:a1b2c3d44d3c2b1a"
2020/11/18 17:10:57 DEBUG : S3 bucket a1b2c3d44d3c2b1a: Waiting for checks to finish
2020/11/18 17:10:57 DEBUG : S3 bucket a1b2c3d44d3c2b1a: Waiting for transfers to finish
2020/11/18 17:10:57 ERROR : test.txt: Failed to copy: BadRequest: Bad Request
	status code: 400, request id: 2D02A6BEB26FA42D, host id: hH4I0RyN1EQd9nqNagPBsOx5YWbFv3Fk4Irn5WHVKQeKiXQ+5N3+894hOUmyQMxRTBVbR78viA0=
2020/11/18 17:10:57 INFO  : There was nothing to transfer
2020/11/18 17:10:57 ERROR : Attempt 1/3 failed with 1 errors and: BadRequest: Bad Request
	status code: 400, request id: 2D02A6BEB26FA42D, host id: hH4I0RyN1EQd9nqNagPBsOx5YWbFv3Fk4Irn5WHVKQeKiXQ+5N3+894hOUmyQMxRTBVbR78viA0=
2020/11/18 17:10:57 DEBUG : S3 bucket a1b2c3d44d3c2b1a: Waiting for checks to finish
2020/11/18 17:10:58 NOTICE: test.txt: Failed to read metadata: BadRequest: Bad Request
	status code: 400, request id: FFCF60C9E0DD1918, host id: 50MWcIyB+utJDP88K4YipkzeMXNAzwM+INh5SXAZnP/bi21vIXOsh30D7GDGBif3fF1R3mTgjQY=
2020/11/18 17:10:58 DEBUG : test.txt: Modification times differ by 29m14.9601555s: 2020-11-18 16:41:43.0462762 -0500 EST, 2020-11-18 17:10:58.0064317 -0500 EST m=+0.584067101
2020/11/18 17:10:58 DEBUG : test.txt: MD5 = cfcd208495d565ef66e7dff9f98764da (Local file system at //?/C:/ex/wg/test)
2020/11/18 17:10:58 DEBUG : test.txt: MD5 = 621b873d5daf93800c53e857a3dd3c04 (S3 bucket a1b2c3d44d3c2b1a)
2020/11/18 17:10:58 DEBUG : test.txt: MD5 differ
2020/11/18 17:10:58 DEBUG : S3 bucket a1b2c3d44d3c2b1a: Waiting for transfers to finish
2020/11/18 17:10:58 ERROR : test.txt: Failed to copy: BadRequest: Bad Request
	status code: 400, request id: 3D2B97D2EA7B0CA0, host id: r5T5rhuwx78ukIEC8KCMQvChUiSx1HGC+cYjJs1hyQMxqsUIC6CLtfMsJd6roGtbJs5ygLQ0IF0=
2020/11/18 17:10:58 INFO  : There was nothing to transfer
2020/11/18 17:10:58 ERROR : Attempt 2/3 failed with 1 errors and: BadRequest: Bad Request
	status code: 400, request id: 3D2B97D2EA7B0CA0, host id: r5T5rhuwx78ukIEC8KCMQvChUiSx1HGC+cYjJs1hyQMxqsUIC6CLtfMsJd6roGtbJs5ygLQ0IF0=
2020/11/18 17:10:58 DEBUG : S3 bucket a1b2c3d44d3c2b1a: Waiting for checks to finish
2020/11/18 17:10:58 NOTICE: test.txt: Failed to read metadata: BadRequest: Bad Request
	status code: 400, request id: C08E0CD4F267527C, host id: XTmh1wtoCs40PEgMb/XU6aQAH4mtTk/ILYKmvTNCQgno/MVyvK0r7/1fd3gpG485J1G7Iya1xuo=
2020/11/18 17:10:58 DEBUG : test.txt: Modification times differ by 29m15.2713708s: 2020-11-18 16:41:43.0462762 -0500 EST, 2020-11-18 17:10:58.317647 -0500 EST m=+0.895282401
2020/11/18 17:10:58 DEBUG : test.txt: MD5 = cfcd208495d565ef66e7dff9f98764da (Local file system at //?/C:/ex/wg/test)
2020/11/18 17:10:58 DEBUG : test.txt: MD5 = 114b69501e3b46209c908e8702eafe6b (S3 bucket a1b2c3d44d3c2b1a)
2020/11/18 17:10:58 DEBUG : test.txt: MD5 differ
2020/11/18 17:10:58 DEBUG : S3 bucket a1b2c3d44d3c2b1a: Waiting for transfers to finish
2020/11/18 17:10:58 ERROR : test.txt: Failed to copy: BadRequest: Bad Request
	status code: 400, request id: 9E784B37A8285962, host id: dwvNQ37QN5FgPX3VbSIPmhxmo5EsI4xA5krTM+iwWvxGbr9g5BAwT/bqkWu4djtmYYBlS8Lq5EM=
2020/11/18 17:10:58 INFO  : There was nothing to transfer
2020/11/18 17:10:58 ERROR : Attempt 3/3 failed with 1 errors and: BadRequest: Bad Request
	status code: 400, request id: 9E784B37A8285962, host id: dwvNQ37QN5FgPX3VbSIPmhxmo5EsI4xA5krTM+iwWvxGbr9g5BAwT/bqkWu4djtmYYBlS8Lq5EM=
2020/11/18 17:10:58 INFO  : 
Transferred:   	         3 / 3 Bytes, 100%, 5 Bytes/s, ETA 0s
Errors:                 1 (retrying may help)
Checks:                 2 / 2, 100%
Elapsed time:         1.0s

2020/11/18 17:10:58 DEBUG : 2 go routines active
2020/11/18 17:10:58 Failed to copy: BadRequest: Bad Request
	status code: 400, request id: 9E784B37A8285962, host id: dwvNQ37QN5FgPX3VbSIPmhxmo5EsI4xA5krTM+iwWvxGbr9g5BAwT/bqkWu4djtmYYBlS8Lq5EM=

ncw · November 19, 2020, 12:51pm

If you are using sse-c then there are some more things you need to put in the config file: https://rclone.org/s3/#s3-sse-customer-algorithm

I'm not sure exactly which of them you need and which are optional but hopefully that will help

asdffdsa · November 19, 2020, 2:26pm

using a program called s3 browser, and using the same key i used with rclone czn8qrbUsT/5y5Hr2i93ImWmIQLCZLOL
i was able to upload and then download that same one byte file to the same aws bucket

i spent many hours trying to get it working with rclone.

i really think something is wrong, perhaps a bug, i have included dump headers at the bottom of the post.

the logs has so many items that do not make sense.

i do not put values into config files, i always use flags as per the log i posted
and the values for the key and md5 are from your post here
https://github.com/rclone/rclone/issues/2827#issuecomment-445753183

--s3-sse-customer-algorithm=AES256 --s3-sse-customer-key="czn8qrbUsT/5y5Hr2i93ImWmIQLCZLOL" --s3-sse-customer-key-md5="ME4ss65LcXQBY2CynVdZyA=="

i am trying to transfer just one file of size one byte.
for example,
at the top of the log is
INFO : There was nothing to transfer
then then rclone does a transfer
then rclone then claims
Transferred: 3 / 3 Bytes, 100%, 7 Bytes/s, ETA 0s
and
Checks: 2 / 2, 100%
and a lot of BadRequest

2020/11/19 10:58:09 DEBUG : rclone: Version "v1.53.2" starting with parameters ["c:\\data\\rclone\\scripts\\rclone.exe" "copy" "C:\\ex\\wg\\test" "awsssectest:a1b2c3d44d3c2b1a" "--s3-sse-customer-algorithm=AES256" "--s3-sse-customer-key=czn8qrbUsT/5y5Hr2i93ImWmIQLCZLOL" "--s3-sse-customer-key-md5=ME4ss65LcXQBY2CynVdZyA==" "--log-file=log.ssec.txt" "--log-level=DEBUG" "--dump=requests"]
2020/11/19 10:58:09 DEBUG : Creating backend with remote "C:\\ex\\wg\\test"
2020/11/19 10:58:09 DEBUG : Using RCLONE_CONFIG_PASS password.
2020/11/19 10:58:09 DEBUG : Using config file from "c:\\data\\rclone\\scripts\\rclone.conf"
2020/11/19 10:58:09 DEBUG : fs cache: renaming cache item "C:\\ex\\wg\\test" to be canonical "//?/C:/ex/wg/test"
2020/11/19 10:58:09 DEBUG : Creating backend with remote "awsssectest:a1b2c3d44d3c2b1a"
2020/11/19 10:58:09 DEBUG : You have specified to dump information. Please be noted that the Accept-Encoding as shown may not be correct in the request and the response may not show Content-Encoding if the go standard libraries auto gzip encoding was in effect. In this case the body of the request will be gunzipped before showing it.
2020/11/19 10:58:09 DEBUG : >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
2020/11/19 10:58:09 DEBUG : HTTP REQUEST (req 0xc00033a600)
2020/11/19 10:58:09 DEBUG : GET /?delimiter=%2F&encoding-type=url&max-keys=1000&prefix= HTTP/1.1
Host: a1b2c3d44d3c2b1a.s3.us-east-1.amazonaws.com
User-Agent: rclone/v1.53.2
Authorization: XXXX
X-Amz-Content-Sha256: e3b0c44298fc1c149afbf4c8996fb92427ae41e4649b934ca495991b7852b855
X-Amz-Date: 20201119T155809Z
Accept-Encoding: gzip

2020/11/19 10:58:09 DEBUG : >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
2020/11/19 10:58:09 DEBUG : <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<
2020/11/19 10:58:09 DEBUG : HTTP RESPONSE (req 0xc00033a600)
2020/11/19 10:58:09 DEBUG : HTTP/1.1 200 OK
Transfer-Encoding: chunked
Content-Type: application/xml
Date: Thu, 19 Nov 2020 15:58:11 GMT
Server: AmazonS3
X-Amz-Bucket-Region: us-east-1
X-Amz-Id-2: neQuattxH1MO2rZxK8/ZfNFH/uS4LJvae0hS35OSDMgMnbMFbPfGNxD4JjaQs0pwH7K2TtZltOQ=
X-Amz-Request-Id: DD853C3AFD51A70D

2020/11/19 10:58:09 DEBUG : <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<
2020/11/19 10:58:09 DEBUG : S3 bucket a1b2c3d44d3c2b1a: Waiting for checks to finish
2020/11/19 10:58:09 DEBUG : S3 bucket a1b2c3d44d3c2b1a: Waiting for transfers to finish
2020/11/19 10:58:09 DEBUG : >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
2020/11/19 10:58:09 DEBUG : HTTP REQUEST (req 0xc0002d4700)
2020/11/19 10:58:09 DEBUG : PUT /test.txt?X-Amz-Algorithm=AWS4-HMAC-SHA256&X-Amz-Credential=AKRTYTRET5YRIBSJGCHQ%2F20201119%2Fus-east-1%2Fs3%2Faws4_request&X-Amz-Date=20201119T155809Z&X-Amz-Expires=900&X-Amz-SignedHeaders=content-md5%3Bcontent-type%3Bhost%3Bx-amz-acl%3Bx-amz-meta-mtime%3Bx-amz-server-side-encryption-customer-algorithm%3Bx-amz-server-side-encryption-customer-key%3Bx-amz-server-side-encryption-customer-key-md5%3Bx-amz-storage-class&X-Amz-Signature=ac173eab24ad0e0d874c4688315c3a9e4a09baa875e2deb8c424a2709068ae4c HTTP/1.1
Host: a1b2c3d44d3c2b1a.s3.us-east-1.amazonaws.com
User-Agent: rclone/v1.53.2
Content-Length: 7
content-md5: kUHednF+CV1N0F8eaGrWqA==
content-type: text/plain; charset=utf-8
x-amz-acl: private
x-amz-meta-mtime: 1601832312.1873045
x-amz-server-side-encryption-customer-algorithm: AES256
x-amz-server-side-encryption-customer-key: Y3puOHFyYlVzVC81eTVIcjJpOTNJbVdtSVFMQ1pMT0w=
x-amz-server-side-encryption-customer-key-md5: ME4ss65LcXQBY2CynVdZyA==
x-amz-storage-class: STANDARD
Accept-Encoding: gzip

hello12
2020/11/19 10:58:09 DEBUG : >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
2020/11/19 10:58:09 DEBUG : <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<
2020/11/19 10:58:09 DEBUG : HTTP RESPONSE (req 0xc0002d4700)
2020/11/19 10:58:09 DEBUG : HTTP/1.1 200 OK
Content-Length: 0
Date: Thu, 19 Nov 2020 15:58:12 GMT
Etag: "fc3ad92866b63255242e885d0b9e04e5"
Server: AmazonS3
X-Amz-Id-2: 9wXfffOvMVmG5QxHxEQlFRHBE0AnLC3+EoxD5AiIYO+u9k7P+N3+0aSHlAAS8tCY+jZCHJg9KGs=
X-Amz-Request-Id: BA8D0908D7CA8187
X-Amz-Server-Side-Encryption-Customer-Algorithm: AES256
X-Amz-Server-Side-Encryption-Customer-Key-Md5: ME4ss65LcXQBY2CynVdZyA==

2020/11/19 10:58:09 DEBUG : <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<
2020/11/19 10:58:09 DEBUG : >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
2020/11/19 10:58:09 DEBUG : HTTP REQUEST (req 0xc000656400)
2020/11/19 10:58:09 DEBUG : HEAD /test.txt HTTP/1.1
Host: a1b2c3d44d3c2b1a.s3.us-east-1.amazonaws.com
User-Agent: rclone/v1.53.2
Authorization: XXXX
X-Amz-Content-Sha256: e3b0c44298fc1c149afbf4c8996fb92427ae41e4649b934ca495991b7852b855
X-Amz-Date: 20201119T155809Z

2020/11/19 10:58:09 DEBUG : >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
2020/11/19 10:58:09 DEBUG : <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<
2020/11/19 10:58:09 DEBUG : HTTP RESPONSE (req 0xc000656400)
2020/11/19 10:58:09 DEBUG : HTTP/1.1 400 Bad Request
Connection: close
Content-Type: application/xml
Date: Thu, 19 Nov 2020 15:58:10 GMT
Server: AmazonS3
X-Amz-Id-2: p+Yd6FvD1C8feZKQpWd8lVucT0i5TO4izyxVw1dHJ/3ZFlOZTM532C88lwlVYXIWEyQZV4AQOMk=
X-Amz-Request-Id: 6A54CAFDB4C2B5B6

2020/11/19 10:58:09 DEBUG : <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<
2020/11/19 10:58:09 ERROR : test.txt: Failed to copy: BadRequest: Bad Request
	status code: 400, request id: 6A54CAFDB4C2B5B6, host id: p+Yd6FvD1C8feZKQpWd8lVucT0i5TO4izyxVw1dHJ/3ZFlOZTM532C88lwlVYXIWEyQZV4AQOMk=
2020/11/19 10:58:09 INFO  : There was nothing to transfer
2020/11/19 10:58:09 ERROR : Attempt 1/3 failed with 1 errors and: BadRequest: Bad Request
	status code: 400, request id: 6A54CAFDB4C2B5B6, host id: p+Yd6FvD1C8feZKQpWd8lVucT0i5TO4izyxVw1dHJ/3ZFlOZTM532C88lwlVYXIWEyQZV4AQOMk=
2020/11/19 10:58:09 DEBUG : >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
2020/11/19 10:58:09 DEBUG : HTTP REQUEST (req 0xc000656800)
2020/11/19 10:58:09 DEBUG : GET /?delimiter=%2F&encoding-type=url&max-keys=1000&prefix= HTTP/1.1
Host: a1b2c3d44d3c2b1a.s3.us-east-1.amazonaws.com
User-Agent: rclone/v1.53.2
Authorization: XXXX
X-Amz-Content-Sha256: e3b0c44298fc1c149afbf4c8996fb92427ae41e4649b934ca495991b7852b855
X-Amz-Date: 20201119T155809Z
Accept-Encoding: gzip

2020/11/19 10:58:09 DEBUG : >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
2020/11/19 10:58:10 DEBUG : <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<
2020/11/19 10:58:10 DEBUG : HTTP RESPONSE (req 0xc000656800)
2020/11/19 10:58:10 DEBUG : HTTP/1.1 200 OK
Transfer-Encoding: chunked
Content-Type: application/xml
Date: Thu, 19 Nov 2020 15:58:12 GMT
Server: AmazonS3
X-Amz-Bucket-Region: us-east-1
X-Amz-Id-2: 72fnltrc6zGnA4cXa58DZDtt2rAqMInAAMqis8jNMKq9u3FoYwpga5mp/fQoYVZksWdKVagjhiw=
X-Amz-Request-Id: 19C323F5E5C1C409

2020/11/19 10:58:10 DEBUG : <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<
2020/11/19 10:58:10 DEBUG : S3 bucket a1b2c3d44d3c2b1a: Waiting for checks to finish
2020/11/19 10:58:10 DEBUG : >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
2020/11/19 10:58:10 DEBUG : HTTP REQUEST (req 0xc000656c00)
2020/11/19 10:58:10 DEBUG : HEAD /test.txt HTTP/1.1
Host: a1b2c3d44d3c2b1a.s3.us-east-1.amazonaws.com
User-Agent: rclone/v1.53.2
Authorization: XXXX
X-Amz-Content-Sha256: e3b0c44298fc1c149afbf4c8996fb92427ae41e4649b934ca495991b7852b855
X-Amz-Date: 20201119T155810Z

2020/11/19 10:58:10 DEBUG : >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
2020/11/19 10:58:10 DEBUG : <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<
2020/11/19 10:58:10 DEBUG : HTTP RESPONSE (req 0xc000656c00)
2020/11/19 10:58:10 DEBUG : HTTP/1.1 400 Bad Request
Connection: close
Content-Type: application/xml
Date: Thu, 19 Nov 2020 15:58:10 GMT
Server: AmazonS3
X-Amz-Id-2: FD7MXewMyfn6oh/jqg2+RizLgizoyuSWkLLWVFIVKYR7TeoPGudldxVEnHylzyJU80rnVpxlcNg=
X-Amz-Request-Id: FEE747289F4FD3E6

2020/11/19 10:58:10 DEBUG : <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<
2020/11/19 10:58:10 NOTICE: test.txt: Failed to read metadata: BadRequest: Bad Request
	status code: 400, request id: FEE747289F4FD3E6, host id: FD7MXewMyfn6oh/jqg2+RizLgizoyuSWkLLWVFIVKYR7TeoPGudldxVEnHylzyJU80rnVpxlcNg=
2020/11/19 10:58:10 DEBUG : test.txt: Modification times differ by 1102h32m57.9245681s: 2020-10-04 13:25:12.1873045 -0400 EDT, 2020-11-19 10:58:10.1118726 -0500 EST m=+0.695058801
2020/11/19 10:58:10 DEBUG : test.txt: MD5 = 9141de76717e095d4dd05f1e686ad6a8 (Local file system at //?/C:/ex/wg/test)
2020/11/19 10:58:10 DEBUG : test.txt: MD5 = fc3ad92866b63255242e885d0b9e04e5 (S3 bucket a1b2c3d44d3c2b1a)
2020/11/19 10:58:10 DEBUG : test.txt: MD5 differ
2020/11/19 10:58:10 DEBUG : S3 bucket a1b2c3d44d3c2b1a: Waiting for transfers to finish
2020/11/19 10:58:10 DEBUG : >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
2020/11/19 10:58:10 DEBUG : HTTP REQUEST (req 0xc0002d4e00)
2020/11/19 10:58:10 DEBUG : PUT /test.txt?X-Amz-Algorithm=AWS4-HMAC-SHA256&X-Amz-Credential=AKRTYTRET5YRIBSJGCHQ%2F20201119%2Fus-east-1%2Fs3%2Faws4_request&X-Amz-Date=20201119T155810Z&X-Amz-Expires=900&X-Amz-SignedHeaders=content-md5%3Bcontent-type%3Bhost%3Bx-amz-acl%3Bx-amz-meta-mtime%3Bx-amz-server-side-encryption-customer-algorithm%3Bx-amz-server-side-encryption-customer-key%3Bx-amz-server-side-encryption-customer-key-md5%3Bx-amz-storage-class&X-Amz-Signature=3405d82d593d115cd8e6e4ededa041e4339a2433405b723140ad172f1c449041 HTTP/1.1
Host: a1b2c3d44d3c2b1a.s3.us-east-1.amazonaws.com
User-Agent: rclone/v1.53.2
Content-Length: 7
content-md5: kUHednF+CV1N0F8eaGrWqA==
content-type: text/plain; charset=utf-8
x-amz-acl: private
x-amz-meta-mtime: 1601832312.1873045
x-amz-server-side-encryption-customer-algorithm: AES256
x-amz-server-side-encryption-customer-key: Y3puOHFyYlVzVC81eTVIcjJpOTNJbVdtSVFMQ1pMT0w=
x-amz-server-side-encryption-customer-key-md5: ME4ss65LcXQBY2CynVdZyA==
x-amz-storage-class: STANDARD
Accept-Encoding: gzip

hello12
2020/11/19 10:58:10 DEBUG : >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
2020/11/19 10:58:10 DEBUG : <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<
2020/11/19 10:58:10 DEBUG : HTTP RESPONSE (req 0xc0002d4e00)
2020/11/19 10:58:10 DEBUG : HTTP/1.1 200 OK
Content-Length: 0
Date: Thu, 19 Nov 2020 15:58:12 GMT
Etag: "ecf6b8ce791f227fbb8d641a78cfbc10"
Server: AmazonS3
X-Amz-Id-2: sKjCpwQPQDJoZU+u2BhjrWchx2rJ2U0XtLMdUVr/LHCM9Re16LV8maSjEt9f5AUBZIQlHm8Rj5I=
X-Amz-Request-Id: 6SAZEPEG5J9X3SFT
X-Amz-Server-Side-Encryption-Customer-Algorithm: AES256
X-Amz-Server-Side-Encryption-Customer-Key-Md5: ME4ss65LcXQBY2CynVdZyA==

2020/11/19 10:58:10 DEBUG : <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<
2020/11/19 10:58:10 DEBUG : >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
2020/11/19 10:58:10 DEBUG : HTTP REQUEST (req 0xc000718800)
2020/11/19 10:58:10 DEBUG : HEAD /test.txt HTTP/1.1
Host: a1b2c3d44d3c2b1a.s3.us-east-1.amazonaws.com
User-Agent: rclone/v1.53.2
Authorization: XXXX
X-Amz-Content-Sha256: e3b0c44298fc1c149afbf4c8996fb92427ae41e4649b934ca495991b7852b855
X-Amz-Date: 20201119T155810Z

2020/11/19 10:58:10 DEBUG : >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
2020/11/19 10:58:10 DEBUG : <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<
2020/11/19 10:58:10 DEBUG : HTTP RESPONSE (req 0xc000718800)
2020/11/19 10:58:10 DEBUG : HTTP/1.1 400 Bad Request
Connection: close
Content-Type: application/xml
Date: Thu, 19 Nov 2020 15:58:10 GMT
Server: AmazonS3
X-Amz-Id-2: hY929VxbomeK7d8b94iCom1GejWJhcZ5JCFjR3cQLQA8I3xdN99OoLbSXC/DlnPTyJA+eYO9MGM=
X-Amz-Request-Id: 6633EC667E120DAA

2020/11/19 10:58:10 DEBUG : <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<
2020/11/19 10:58:10 ERROR : test.txt: Failed to copy: BadRequest: Bad Request
	status code: 400, request id: 6633EC667E120DAA, host id: hY929VxbomeK7d8b94iCom1GejWJhcZ5JCFjR3cQLQA8I3xdN99OoLbSXC/DlnPTyJA+eYO9MGM=
2020/11/19 10:58:10 INFO  : There was nothing to transfer
2020/11/19 10:58:10 ERROR : Attempt 2/3 failed with 1 errors and: BadRequest: Bad Request
	status code: 400, request id: 6633EC667E120DAA, host id: hY929VxbomeK7d8b94iCom1GejWJhcZ5JCFjR3cQLQA8I3xdN99OoLbSXC/DlnPTyJA+eYO9MGM=
2020/11/19 10:58:10 DEBUG : >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
2020/11/19 10:58:10 DEBUG : HTTP REQUEST (req 0xc000718d00)
2020/11/19 10:58:10 DEBUG : GET /?delimiter=%2F&encoding-type=url&max-keys=1000&prefix= HTTP/1.1
Host: a1b2c3d44d3c2b1a.s3.us-east-1.amazonaws.com
User-Agent: rclone/v1.53.2
Authorization: XXXX
X-Amz-Content-Sha256: e3b0c44298fc1c149afbf4c8996fb92427ae41e4649b934ca495991b7852b855
X-Amz-Date: 20201119T155810Z
Accept-Encoding: gzip

2020/11/19 10:58:10 DEBUG : >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
2020/11/19 10:58:10 DEBUG : <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<
2020/11/19 10:58:10 DEBUG : HTTP RESPONSE (req 0xc000718d00)
2020/11/19 10:58:10 DEBUG : HTTP/1.1 200 OK
Transfer-Encoding: chunked
Content-Type: application/xml
Date: Thu, 19 Nov 2020 15:58:12 GMT
Server: AmazonS3
X-Amz-Bucket-Region: us-east-1
X-Amz-Id-2: r83OrIyEiiiTiCRIRLTxxIx+ASFGafT+wVQspQsqGLinotUwPUSkgQ85Ucnj/3W5z3I+8EHxKF8=
X-Amz-Request-Id: FAD88C3E86F108E2

2020/11/19 10:58:10 DEBUG : <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<
2020/11/19 10:58:11 DEBUG : S3 bucket a1b2c3d44d3c2b1a: Waiting for checks to finish
2020/11/19 10:58:11 DEBUG : >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
2020/11/19 10:58:11 DEBUG : HTTP REQUEST (req 0xc000136700)
2020/11/19 10:58:11 DEBUG : HEAD /test.txt HTTP/1.1
Host: a1b2c3d44d3c2b1a.s3.us-east-1.amazonaws.com
User-Agent: rclone/v1.53.2
Authorization: XXXX
X-Amz-Content-Sha256: e3b0c44298fc1c149afbf4c8996fb92427ae41e4649b934ca495991b7852b855
X-Amz-Date: 20201119T155811Z

2020/11/19 10:58:11 DEBUG : >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
2020/11/19 10:58:11 DEBUG : <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<
2020/11/19 10:58:11 DEBUG : HTTP RESPONSE (req 0xc000136700)
2020/11/19 10:58:11 DEBUG : HTTP/1.1 400 Bad Request
Connection: close
Content-Type: application/xml
Date: Thu, 19 Nov 2020 15:58:12 GMT
Server: AmazonS3
X-Amz-Id-2: 7kb3w3ROL4fE7gg93PY9Nn/TQCnEZM/GihNHaNOH/j/bHBmJqi/vgaXgEsXvtlEazyCz+n7clN4=
X-Amz-Request-Id: C41FAFD628060C8A

2020/11/19 10:58:11 DEBUG : <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<
2020/11/19 10:58:11 NOTICE: test.txt: Failed to read metadata: BadRequest: Bad Request
	status code: 400, request id: C41FAFD628060C8A, host id: 7kb3w3ROL4fE7gg93PY9Nn/TQCnEZM/GihNHaNOH/j/bHBmJqi/vgaXgEsXvtlEazyCz+n7clN4=
2020/11/19 10:58:11 DEBUG : test.txt: Modification times differ by 1102h32m58.8328254s: 2020-10-04 13:25:12.1873045 -0400 EDT, 2020-11-19 10:58:11.0201299 -0500 EST m=+1.603316101
2020/11/19 10:58:11 DEBUG : test.txt: MD5 = 9141de76717e095d4dd05f1e686ad6a8 (Local file system at //?/C:/ex/wg/test)
2020/11/19 10:58:11 DEBUG : test.txt: MD5 = ecf6b8ce791f227fbb8d641a78cfbc10 (S3 bucket a1b2c3d44d3c2b1a)
2020/11/19 10:58:11 DEBUG : test.txt: MD5 differ
2020/11/19 10:58:11 DEBUG : S3 bucket a1b2c3d44d3c2b1a: Waiting for transfers to finish
2020/11/19 10:58:11 DEBUG : >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
2020/11/19 10:58:11 DEBUG : HTTP REQUEST (req 0xc000656600)
2020/11/19 10:58:11 DEBUG : PUT /test.txt?X-Amz-Algorithm=AWS4-HMAC-SHA256&X-Amz-Credential=AKRTYTRET5YRIBSJGCHQ%2F20201119%2Fus-east-1%2Fs3%2Faws4_request&X-Amz-Date=20201119T155811Z&X-Amz-Expires=900&X-Amz-SignedHeaders=content-md5%3Bcontent-type%3Bhost%3Bx-amz-acl%3Bx-amz-meta-mtime%3Bx-amz-server-side-encryption-customer-algorithm%3Bx-amz-server-side-encryption-customer-key%3Bx-amz-server-side-encryption-customer-key-md5%3Bx-amz-storage-class&X-Amz-Signature=859423b5abe85647068d678c52c04f5ea53e31aae581de1af4b7dfd2b3dbe8a8 HTTP/1.1
Host: a1b2c3d44d3c2b1a.s3.us-east-1.amazonaws.com
User-Agent: rclone/v1.53.2
Content-Length: 7
content-md5: kUHednF+CV1N0F8eaGrWqA==
content-type: text/plain; charset=utf-8
x-amz-acl: private
x-amz-meta-mtime: 1601832312.1873045
x-amz-server-side-encryption-customer-algorithm: AES256
x-amz-server-side-encryption-customer-key: Y3puOHFyYlVzVC81eTVIcjJpOTNJbVdtSVFMQ1pMT0w=
x-amz-server-side-encryption-customer-key-md5: ME4ss65LcXQBY2CynVdZyA==
x-amz-storage-class: STANDARD
Accept-Encoding: gzip

hello12
2020/11/19 10:58:11 DEBUG : >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
2020/11/19 10:58:11 DEBUG : <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<
2020/11/19 10:58:11 DEBUG : HTTP RESPONSE (req 0xc000656600)
2020/11/19 10:58:11 DEBUG : HTTP/1.1 200 OK
Content-Length: 0
Date: Thu, 19 Nov 2020 15:58:13 GMT
Etag: "a1792011540c219c7846bea7fa9a4145"
Server: AmazonS3
X-Amz-Id-2: x/SuaKAhRzERS+je6peo24NDgv1BCdDBtytxpTbFK27OmUx1mwEH2DFRkXOKvttYH6dfXqQN9xc=
X-Amz-Request-Id: C1B4C2EAEF49C06F
X-Amz-Server-Side-Encryption-Customer-Algorithm: AES256
X-Amz-Server-Side-Encryption-Customer-Key-Md5: ME4ss65LcXQBY2CynVdZyA==

2020/11/19 10:58:11 DEBUG : <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<
2020/11/19 10:58:11 DEBUG : >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
2020/11/19 10:58:11 DEBUG : HTTP REQUEST (req 0xc000137000)
2020/11/19 10:58:11 DEBUG : HEAD /test.txt HTTP/1.1
Host: a1b2c3d44d3c2b1a.s3.us-east-1.amazonaws.com
User-Agent: rclone/v1.53.2
Authorization: XXXX
X-Amz-Content-Sha256: e3b0c44298fc1c149afbf4c8996fb92427ae41e4649b934ca495991b7852b855
X-Amz-Date: 20201119T155811Z

2020/11/19 10:58:11 DEBUG : >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
2020/11/19 10:58:11 DEBUG : <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<
2020/11/19 10:58:11 DEBUG : HTTP RESPONSE (req 0xc000137000)
2020/11/19 10:58:11 DEBUG : HTTP/1.1 400 Bad Request
Connection: close
Content-Type: application/xml
Date: Thu, 19 Nov 2020 15:58:12 GMT
Server: AmazonS3
X-Amz-Id-2: 0bxFxRS0NzyXH5uRyF2tGGw8w8FJBo0J9zHu2ptuV3WVeD19iJyZDPHIfFmI8ShWBQ7ckBqpRCw=
X-Amz-Request-Id: 126F1274A8272EF5

2020/11/19 10:58:11 DEBUG : <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<
2020/11/19 10:58:11 ERROR : test.txt: Failed to copy: BadRequest: Bad Request
	status code: 400, request id: 126F1274A8272EF5, host id: 0bxFxRS0NzyXH5uRyF2tGGw8w8FJBo0J9zHu2ptuV3WVeD19iJyZDPHIfFmI8ShWBQ7ckBqpRCw=
2020/11/19 10:58:11 INFO  : There was nothing to transfer
2020/11/19 10:58:11 ERROR : Attempt 3/3 failed with 1 errors and: BadRequest: Bad Request
	status code: 400, request id: 126F1274A8272EF5, host id: 0bxFxRS0NzyXH5uRyF2tGGw8w8FJBo0J9zHu2ptuV3WVeD19iJyZDPHIfFmI8ShWBQ7ckBqpRCw=
2020/11/19 10:58:11 INFO  : 
Transferred:   	        21 / 21 Bytes, 100%, 37 Bytes/s, ETA 0s
Errors:                 1 (retrying may help)
Checks:                 2 / 2, 100%
Elapsed time:         1.7s

2020/11/19 10:58:11 DEBUG : 2 go routines active
2020/11/19 10:58:11 Failed to copy: BadRequest: Bad Request
	status code: 400, request id: 126F1274A8272EF5, host id: 0bxFxRS0NzyXH5uRyF2tGGw8w8FJBo0J9zHu2ptuV3WVeD19iJyZDPHIfFmI8ShWBQ7ckBqpRCw=

ncw · November 20, 2020, 12:39pm

asdffdsa:

2020/11/19 10:58:09 DEBUG : HTTP REQUEST (req 0xc000656400)
2020/11/19 10:58:09 DEBUG : HEAD /test.txt HTTP/1.1
Host: a1b2c3d44d3c2b1a.s3.us-east-1.amazonaws.com
User-Agent: rclone/v1.53.2
Authorization: XXXX
X-Amz-Content-Sha256: e3b0c44298fc1c149afbf4c8996fb92427ae41e4649b934ca495991b7852b855
X-Amz-Date: 20201119T155809Z

2020/11/19 10:58:09 DEBUG : >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
2020/11/19 10:58:09 DEBUG : <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<
2020/11/19 10:58:09 DEBUG : HTTP RESPONSE (req 0xc000656400)
2020/11/19 10:58:09 DEBUG : HTTP/1.1 400 Bad Request

Very useful log - thank you.

So the PUT the object is working fine, but the HEAD rclone is doing to check it is OK is failing - hence the confusion.

It says in the docs here: https://docs.aws.amazon.com/AmazonS3/latest/API/API_HeadObject.html

If you encrypt an object by using server-side encryption with customer-provided encryption keys (SSE-C) when you store the object in Amazon S3, then when you retrieve the metadata from the object, you must use the following headers:

x-amz-server-side-encryption-customer-algorithm
x-amz-server-side-encryption-customer-key
x-amz-server-side-encryption-customer-key-MD5

Rclone is not doing that - you can see that quite clearly in the headers in your log, so I think that is the bug.

Have a go with this

v1.54.0-beta.4905.cbd93519c.fix-s3-sse on branch fix-s3-sse (uploaded in 15-30 mins)

Note that you don't need to set --s3-sse-customer-key-md5 any more - rclone will calculate that for you.

asdffdsa · November 20, 2020, 2:23pm

well, we are making progress.

the errors in the log are gone but the behavior is the same
that the file is copied as is, no encryption.

2020/11/20 09:26:34 DEBUG : rclone: Version "v1.54.0-beta.4905.cbd93519c.fix-s3-sse" starting with parameters ["c:\\data\\rclone\\versions\\rclone-v1.54.0-beta.4905.cbd93519c.fix-s3-sse-windows-amd64\\rclone.exe" "copy" "C:\\ex\\wg\\test" "awsssectest:a1b2c3d44d3c2b1a" "--s3-sse-customer-algorithm=AES256" "--s3-sse-customer-key=czn8qrbUsT/5y5Hr2i93ImWmIQLCZLOL" "--log-file=log.ssec.txt" "--log-level=DEBUG" "--config=c:\\data\\rclone\\scripts\\rclone.conf" "--dump" "headers"]
2020/11/20 09:26:34 DEBUG : Creating backend with remote "C:\\ex\\wg\\test"
2020/11/20 09:26:34 DEBUG : Using RCLONE_CONFIG_PASS password.
2020/11/20 09:26:34 DEBUG : Using config file from "c:\\data\\rclone\\scripts\\rclone.conf"
2020/11/20 09:26:34 DEBUG : fs cache: renaming cache item "C:\\ex\\wg\\test" to be canonical "//?/C:/ex/wg/test"
2020/11/20 09:26:34 DEBUG : Creating backend with remote "awsssectest:a1b2c3d44d3c2b1a"
2020/11/20 09:26:34 DEBUG : You have specified to dump information. Please be noted that the Accept-Encoding as shown may not be correct in the request and the response may not show Content-Encoding if the go standard libraries auto gzip encoding was in effect. In this case the body of the request will be gunzipped before showing it.
2020/11/20 09:26:34 DEBUG : You have specified to dump information. Please be noted that the Accept-Encoding as shown may not be correct in the request and the response may not show Content-Encoding if the go standard libraries auto gzip encoding was in effect. In this case the body of the request will be gunzipped before showing it.
2020/11/20 09:26:34 DEBUG : >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
2020/11/20 09:26:34 DEBUG : HTTP REQUEST (req 0xc000027200)
2020/11/20 09:26:34 DEBUG : GET /?delimiter=%2F&encoding-type=url&max-keys=1000&prefix= HTTP/1.1
Host: a1b2c3d44d3c2b1a.s3.us-east-1.amazonaws.com
User-Agent: rclone/v1.54.0-beta.4905.cbd93519c.fix-s3-sse
Authorization: XXXX
X-Amz-Content-Sha256: e3b0c44298fc1c149afbf4c8996fb92427ae41e4649b934ca495991b7852b855
X-Amz-Date: 20201120T142634Z
Accept-Encoding: gzip

2020/11/20 09:26:34 DEBUG : >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
2020/11/20 09:26:34 DEBUG : <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<
2020/11/20 09:26:34 DEBUG : HTTP RESPONSE (req 0xc000027200)
2020/11/20 09:26:34 DEBUG : HTTP/1.1 200 OK
Transfer-Encoding: chunked
Content-Type: application/xml
Date: Fri, 20 Nov 2020 14:26:35 GMT
Server: AmazonS3
X-Amz-Bucket-Region: us-east-1
X-Amz-Id-2: CD/AiDG6oOtqDe22P/fTG6j898i7x+Ln3YKZUhqjLmDtfdGMqMQgzLknXGU2QpGmyxXsF8qUVMI=
X-Amz-Request-Id: E5E4CD954866A3C9

2020/11/20 09:26:34 DEBUG : <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<
2020/11/20 09:26:34 DEBUG : S3 bucket a1b2c3d44d3c2b1a: Waiting for checks to finish
2020/11/20 09:26:34 DEBUG : S3 bucket a1b2c3d44d3c2b1a: Waiting for transfers to finish
2020/11/20 09:26:34 DEBUG : >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
2020/11/20 09:26:34 DEBUG : HTTP REQUEST (req 0xc000027700)
2020/11/20 09:26:34 DEBUG : PUT /test.txt?X-Amz-Algorithm=AWS4-HMAC-SHA256&X-Amz-Credential=AKIAJEOETZYRIBSJGCHQ%2F20201120%2Fus-east-1%2Fs3%2Faws4_request&X-Amz-Date=20201120T142634Z&X-Amz-Expires=900&X-Amz-SignedHeaders=content-md5%3Bcontent-type%3Bhost%3Bx-amz-acl%3Bx-amz-meta-mtime%3Bx-amz-server-side-encryption-customer-algorithm%3Bx-amz-server-side-encryption-customer-key%3Bx-amz-server-side-encryption-customer-key-md5%3Bx-amz-storage-class&X-Amz-Signature=f79b17a6004cd7f0e24487e741a5f2b158c2d365dfff268eee1846a88994022e HTTP/1.1
Host: a1b2c3d44d3c2b1a.s3.us-east-1.amazonaws.com
User-Agent: rclone/v1.54.0-beta.4905.cbd93519c.fix-s3-sse
Content-Length: 7
content-md5: kUHednF+CV1N0F8eaGrWqA==
content-type: text/plain; charset=utf-8
x-amz-acl: private
x-amz-meta-mtime: 1601832312.1873045
x-amz-server-side-encryption-customer-algorithm: AES256
x-amz-server-side-encryption-customer-key: Y3puOHFyYlVzVC81eTVIcjJpOTNJbVdtSVFMQ1pMT0w=
x-amz-server-side-encryption-customer-key-md5: ME4ss65LcXQBY2CynVdZyA==
x-amz-storage-class: STANDARD
Accept-Encoding: gzip

2020/11/20 09:26:34 DEBUG : >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
2020/11/20 09:26:34 DEBUG : <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<
2020/11/20 09:26:34 DEBUG : HTTP RESPONSE (req 0xc000027700)
2020/11/20 09:26:34 DEBUG : HTTP/1.1 200 OK
Content-Length: 0
Date: Fri, 20 Nov 2020 14:26:35 GMT
Etag: "8bc6ce89d12dd4c86c01e2d221cda6d8"
Server: AmazonS3
X-Amz-Id-2: ZjjH96ogN+L4whlmwTVHVXUyHSzIC/G2PgNheNhT4j5Bl1tSYwbmbQ7Rex4dE+nn7e/OlEQhias=
X-Amz-Request-Id: 99CCE8E620B3B5D8
X-Amz-Server-Side-Encryption-Customer-Algorithm: AES256
X-Amz-Server-Side-Encryption-Customer-Key-Md5: ME4ss65LcXQBY2CynVdZyA==

2020/11/20 09:26:34 DEBUG : <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<
2020/11/20 09:26:34 DEBUG : >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
2020/11/20 09:26:34 DEBUG : HTTP REQUEST (req 0xc000027c00)
2020/11/20 09:26:34 DEBUG : HEAD /test.txt HTTP/1.1
Host: a1b2c3d44d3c2b1a.s3.us-east-1.amazonaws.com
User-Agent: rclone/v1.54.0-beta.4905.cbd93519c.fix-s3-sse
Authorization: XXXX
X-Amz-Content-Sha256: e3b0c44298fc1c149afbf4c8996fb92427ae41e4649b934ca495991b7852b855
X-Amz-Date: 20201120T142634Z
X-Amz-Server-Side-Encryption-Customer-Algorithm: AES256
X-Amz-Server-Side-Encryption-Customer-Key: Y3puOHFyYlVzVC81eTVIcjJpOTNJbVdtSVFMQ1pMT0w=
X-Amz-Server-Side-Encryption-Customer-Key-Md5: ME4ss65LcXQBY2CynVdZyA==

2020/11/20 09:26:34 DEBUG : >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
2020/11/20 09:26:34 DEBUG : <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<
2020/11/20 09:26:34 DEBUG : HTTP RESPONSE (req 0xc000027c00)
2020/11/20 09:26:34 DEBUG : HTTP/1.1 200 OK
Content-Length: 7
Accept-Ranges: bytes
Content-Type: text/plain; charset=utf-8
Date: Fri, 20 Nov 2020 14:26:35 GMT
Etag: "8bc6ce89d12dd4c86c01e2d221cda6d8"
Last-Modified: Fri, 20 Nov 2020 14:26:35 GMT
Server: AmazonS3
X-Amz-Id-2: +xT7ejG7poIowDuXoFoV79t7lbXzV9qtBqxNHpyIb2yo+uUJbv8JCZGP0CnUkEBEFMGs61+Zcrs=
X-Amz-Meta-Mtime: 1601832312.1873045
X-Amz-Request-Id: 2649AE3A450F9933
X-Amz-Server-Side-Encryption-Customer-Algorithm: AES256
X-Amz-Server-Side-Encryption-Customer-Key-Md5: ME4ss65LcXQBY2CynVdZyA==

2020/11/20 09:26:34 DEBUG : <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<
2020/11/20 09:26:34 INFO  : test.txt: Copied (new)
2020/11/20 09:26:34 INFO  : 
Transferred:   	         7 / 7 Bytes, 100%, 27 Bytes/s, ETA 0s
Transferred:            1 / 1, 100%
Elapsed time:         0.5s

2020/11/20 09:26:34 DEBUG : 6 go routines active

ncw · November 20, 2020, 3:30pm

Good!

It is Amazon that encrypts and decrypts the file, not rclone for SSE-C. So I was wondering how you could tell?

asdffdsa · November 20, 2020, 4:56pm

did more testing, seems that aws did encrypt the file.
if rclones tries to download without the sse-c flags then amazon complains
failed to open source object: InvalidRequest: The object was stored using a form of Server Side Encryption

now the problem is that

rclone does not compare checksum on upload/download.
rclone check cannot compare

also, seems that s3.browser set these headers, the second value is the sha256 of the original file.
seems that

the leading 0 is compression disabled
the next is 1, encryption is enabled
next is sha-256
next is the file size of 7

and rclone hashsum does not support sha-256.

perhaps cryptcheck can be changed.
it already will crypt source files using md5 to compare to dest files.
should not be to hard to crypt source using sha-256 and compare to dest.

ncw · November 22, 2020, 12:21pm

Great

What I can do is add metadata, the same as we do for large files with the md5sum of the decrypted data. This will enable checksums to be compared and rclone check to work. If you want to see how that would work, try uploading a file with --s3-upload-cutoff 0. Rclone will add a header (this is a base64 encoded md5 checksum)

X-Amz-Meta-Md5chksum: JeMXdz8wjkRsyExQOm0fhQ==

Is that worth doing do you think?

Interesting... I don't think that is standardised though - as in it is just what s3.browser does.

asdffdsa · November 22, 2020, 4:18pm

that work-around worked

here is an idea.
to switch rclone from using md5 to AES.
https://golang.org/pkg/crypto/aes/ supports hardware crypto.
i have found many internet websites that test the speed increases for encryption, for example, with openssl and openvpn.

my logic is that most/all cpu processors have hardware support for AES.
so calculating checksum should be faster, use less cpu, perhaps less ram.

might make a difference for vm in cloud that have limited cpu but can use hardware encryption.
limited devices like raspberry pi would be much faster, use less cpu and ram resources.

that X-Amz-Meta-Md5chksum could be X-Amz-Meta-AESchksum
rclone check would use AES.
crypt remote would use AES to encrypt files
cryptcheck would use AES to check files.
the chunker remote would have an option for AES256
rclone hashsum would have an option for AES256

what do you think?

ncw · November 23, 2020, 12:13pm

OK here is a version of rclone which should work without that work-around

v1.54.0-beta.4907.78e3ba830.fix-s3-sse on branch fix-s3-sse (uploaded in 15-30 mins)

AES is encryption rather than hashing. You can use it for hashing if you are determined enough though!

However MD5 is pretty fast - it is normally reading the file off the disk that is the bottleneck.

Rclone (on my puny laptop) can run MD5SUM at 500MB/s per core.

Note that crypt uses a very efficient encryption - one was that was designed to work fast on CPUs and not need hardware support.

asdffdsa · November 23, 2020, 3:26pm

thanks, that worked.

i have a customer that wanted files uploaded to have encryption.
when i suggested rclone, he was against using a third-party tool to encrypt that might someday not be supported or have bugs, etc..
and with the issue that created v1.53.3, i guess he might have a point.

files had to be encrypted by aws using sse-c as he did not want aws to have the key.

so that would mean i could not use rclone.

now i have a solution where i can use sse-c, rclone sync and rclone check.
a complete solution once v1.5.4.0 is released.

i will make another donation.

ncw · November 23, 2020, 9:16pm

Thanks for explaining the use case.

Yes I think SSE / SSE-C are now fully supported which is great.

ncw · November 25, 2020, 12:29pm

I've merged the SSE-C support to master now which means it will be in the latest beta in 15-30 mins and released in v1.54

system · January 25, 2021, 8:29am

This topic was automatically closed 60 days after the last reply. New replies are no longer allowed.