Bug #17076
closedAWS S3 Version 4 signatures fail sometimes.
Added by Jan Hugo Prins over 7 years ago. Updated almost 7 years ago.
0%
Description
When you use Version 4 signatures from Java AWS client or from s3cmd some file transfers fail with a Signature Failure.
Below is a Debug trace of a PUT filetransfer towards a Ceph cluster with a RadosGateway doing S3.
2016-08-18 17:26:33.864031 7ff155ffb700 1 ====== starting new request req=0x7ff155ff5710 =====
2016-08-18 17:26:33.864046 7ff155ffb700 2 req 624:0.000015::PUT /Photos/Options/BMW/SERIES+1/2012/216/180x102.jpg::initializing for trans_id = tx000000000000000000270-0057b5d3a9-25c26-default
2016-08-18 17:26:33.864051 7ff155ffb700 10 host=testpool.s3.lan.betterbe.com
2016-08-18 17:26:33.864058 7ff155ffb700 20 subdomain=testpool domain=s3.lan.betterbe.com in_hosted_domain=1 in_hosted_domain_s3website=0
2016-08-18 17:26:33.864070 7ff155ffb700 10 meta>> HTTP_X_AMZ_CONTENT_SHA256
2016-08-18 17:26:33.864074 7ff155ffb700 10 meta>> HTTP_X_AMZ_DATE
2016-08-18 17:26:33.864077 7ff155ffb700 10 meta>> HTTP_X_AMZ_META_S3CMD_ATTRS
2016-08-18 17:26:33.864080 7ff155ffb700 10 meta>> HTTP_X_AMZ_STORAGE_CLASS
2016-08-18 17:26:33.864085 7ff155ffb700 10 x>> x-amz-content-sha256:efa99638b4246a2a7c273b397d770195091daa696b3c9cf5bc1aff613f8435db
2016-08-18 17:26:33.864086 7ff155ffb700 10 x>> x-amz-date:20160818T152633Z
2016-08-18 17:26:33.864087 7ff155ffb700 10 x>> x-amz-meta-s3cmd-attrs:uid:1022/gname:betterbe/gid:200/mode:33206/mtime:1355761202/atime:1355761202/md5:6b42337318519c0caab059eb7e59c00c/ctime:1375889848
2016-08-18 17:26:33.864089 7ff155ffb700 10 x>> x-amz-storage-class:STANDARD
2016-08-18 17:26:33.864103 7ff155ffb700 20 get_handler handler=22RGWHandler_REST_Obj_S3
2016-08-18 17:26:33.864107 7ff155ffb700 10 handler=22RGWHandler_REST_Obj_S3
2016-08-18 17:26:33.864109 7ff155ffb700 2 req 624:0.000077:s3:PUT /Photos/Options/BMW/SERIES+1/2012/216/180x102.jpg::getting op 1
2016-08-18 17:26:33.864113 7ff155ffb700 10 op=21RGWPutObj_ObjStore_S3
2016-08-18 17:26:33.864114 7ff155ffb700 2 req 624:0.000083:s3:PUT /Photos/Options/BMW/SERIES+1/2012/216/180x102.jpg:put_obj:authorizing
2016-08-18 17:26:33.864131 7ff155ffb700 10 v4 signedheaders format = content-length;content-type;host;x-amz-content-sha256;x-amz-date;x-amz-meta-s3cmd-attrs;x-amz-storage-class
2016-08-18 17:26:33.864134 7ff155ffb700 10 v4 signature format = abbeb6af798b2aad58cd398491698f863253f3859d22b4c9558cc808159d256d
2016-08-18 17:26:33.864139 7ff155ffb700 10 v4 credential format = JOKWTDNBNWUGKY3UMIOR/20160818/NL/s3/aws4_request
2016-08-18 17:26:33.864141 7ff155ffb700 10 access key id = xxxxxxxxxxxxxxxxxxxx
2016-08-18 17:26:33.864143 7ff155ffb700 10 credential scope = 20160818/NL/s3/aws4_request
2016-08-18 17:26:33.864177 7ff155ffb700 10 canonical headers format = content-length:4354
content-type:image/jpeg
host:testpool.s3.lan.betterbe.com
x-amz-content-sha256:efa99638b4246a2a7c273b397d770195091daa696b3c9cf5bc1aff613f8435db
x-amz-date:20160818T152633Z
x-amz-meta-s3cmd-attrs:uid:1022/gname:betterbe/gid:200/mode:33206/mtime:1355761202/atime:1355761202/md5:6b42337318519c0caab059eb7e59c00c/ctime:1375889848
x-amz-storage-class:STANDARD
2016-08-18 17:26:33.864180 7ff155ffb700 10 body content detected... delaying v4 auth
2016-08-18 17:26:33.864184 7ff155ffb700 2 req 624:0.000153:s3:PUT /Photos/Options/BMW/SERIES+1/2012/216/180x102.jpg:put_obj:normalizing buckets and tenants
2016-08-18 17:26:33.864188 7ff155ffb700 10 s->object=Photos/Options/BMW/SERIES+1/2012/216/180x102.jpg s->bucket=testpool
2016-08-18 17:26:33.864191 7ff155ffb700 2 req 624:0.000160:s3:PUT /Photos/Options/BMW/SERIES+1/2012/216/180x102.jpg:put_obj:init permissions
2016-08-18 17:26:33.864212 7ff155ffb700 15 decode_policy Read AccessControlPolicy<AccessControlPolicy xmlns="http://s3.amazonaws.com/doc/2006-03-01/"><Owner><ID>bofh</ID><DisplayName>bofh</DisplayName></Owner><AccessControlList><Grant><Grantee xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance" xsi:type="CanonicalUser"><ID>bofh</ID><DisplayName>bofh</DisplayName></Grantee><Permission>FULL_CONTROL</Permission></Grant></AccessControlList></AccessControlPolicy>
2016-08-18 17:26:33.864222 7ff155ffb700 2 req 624:0.000190:s3:PUT /Photos/Options/BMW/SERIES+1/2012/216/180x102.jpg:put_obj:recalculating target
2016-08-18 17:26:33.864225 7ff155ffb700 2 req 624:0.000193:s3:PUT /Photos/Options/BMW/SERIES+1/2012/216/180x102.jpg:put_obj:reading permissions
2016-08-18 17:26:33.864227 7ff155ffb700 2 req 624:0.000196:s3:PUT /Photos/Options/BMW/SERIES+1/2012/216/180x102.jpg:put_obj:init op
2016-08-18 17:26:33.864230 7ff155ffb700 2 req 624:0.000199:s3:PUT /Photos/Options/BMW/SERIES+1/2012/216/180x102.jpg:put_obj:verifying op mask
2016-08-18 17:26:33.864233 7ff155ffb700 20 required_mask= 2 user.op_mask=7
2016-08-18 17:26:33.864234 7ff155ffb700 2 req 624:0.000203:s3:PUT /Photos/Options/BMW/SERIES+1/2012/216/180x102.jpg:put_obj:verifying op permissions
2016-08-18 17:26:33.864237 7ff155ffb700 5 Searching permissions for uid=bofh mask=50
2016-08-18 17:26:33.864239 7ff155ffb700 5 Found permission: 15
2016-08-18 17:26:33.864240 7ff155ffb700 5 Searching permissions for group=1 mask=50
2016-08-18 17:26:33.864242 7ff155ffb700 5 Permissions for group not found
2016-08-18 17:26:33.864243 7ff155ffb700 5 Searching permissions for group=2 mask=50
2016-08-18 17:26:33.864244 7ff155ffb700 5 Permissions for group not found
2016-08-18 17:26:33.864245 7ff155ffb700 5 Getting permissions id=bofh owner=bofh perm=2
2016-08-18 17:26:33.864247 7ff155ffb700 10 uid=bofh requested perm (type)=2, policy perm=2, user_perm_mask=2, acl perm=2
2016-08-18 17:26:33.864248 7ff155ffb700 2 req 624:0.000217:s3:PUT /Photos/Options/BMW/SERIES+1/2012/216/180x102.jpg:put_obj:verifying op params
2016-08-18 17:26:33.864251 7ff155ffb700 2 req 624:0.000220:s3:PUT /Photos/Options/BMW/SERIES+1/2012/216/180x102.jpg:put_obj:pre-executing
2016-08-18 17:26:33.864253 7ff155ffb700 2 req 624:0.000222:s3:PUT /Photos/Options/BMW/SERIES+1/2012/216/180x102.jpg:put_obj:executing
2016-08-18 17:26:33.864410 7ff155ffb700 10 payload request hash = efa99638b4246a2a7c273b397d770195091daa696b3c9cf5bc1aff613f8435db
2016-08-18 17:26:33.864441 7ff155ffb700 10 canonical request = PUT
/Photos/Options/BMW/SERIES+1/2012/216/180x102.jpg
content-length:4354
content-type:image/jpeg
host:testpool.s3.lan.betterbe.com
x-amz-content-sha256:efa99638b4246a2a7c273b397d770195091daa696b3c9cf5bc1aff613f8435db
x-amz-date:20160818T152633Z
x-amz-meta-s3cmd-attrs:uid:1022/gname:betterbe/gid:200/mode:33206/mtime:1355761202/atime:1355761202/md5:6b42337318519c0caab059eb7e59c00c/ctime:1375889848
x-amz-storage-class:STANDARD
content-length;content-type;host;x-amz-content-sha256;x-amz-date;x-amz-meta-s3cmd-attrs;x-amz-storage-class
efa99638b4246a2a7c273b397d770195091daa696b3c9cf5bc1aff613f8435db
2016-08-18 17:26:33.864443 7ff155ffb700 10 canonical request hash = fd2ecba2d71a472b35ccaacaed10dcdf929f4bfd234f4fbf643adc65994af62c
2016-08-18 17:26:33.864447 7ff155ffb700 10 string to sign = AWS4-HMAC-SHA256
20160818T152633Z
20160818/NL/s3/aws4_request
fd2ecba2d71a472b35ccaacaed10dcdf929f4bfd234f4fbf643adc65994af62c
2016-08-18 17:26:33.864509 7ff155ffb700 10 date_k = 7e721037098701e49bf42812455904e757ffafdc6eef0367ba6353af29e3dcd1
2016-08-18 17:26:33.864544 7ff155ffb700 10 region_k = 01ba8a474c87a4c6698876b725a2e8710daefb0023aae39490b8a756dc593d6d
2016-08-18 17:26:33.864581 7ff155ffb700 10 service_k = 04d088512278902e8366f92885833e794e23e43a2d53438f6284e3ea0e823702
2016-08-18 17:26:33.864613 7ff155ffb700 10 signing_k = be4aaedf9a4136841f1dc510042d102d3f34fd976b360248e932bcb664f49f0c
2016-08-18 17:26:33.864650 7ff155ffb700 10 signature_k = e13d83bcd1f52103e9056add844e0037accb71436faee1a3e0048dd6c25cd4b6
2016-08-18 17:26:33.864657 7ff155ffb700 10 new signature = e13d83bcd1f52103e9056add844e0037accb71436faee1a3e0048dd6c25cd4b6
2016-08-18 17:26:33.864658 7ff155ffb700 10 ----------------------------- Verifying signatures
2016-08-18 17:26:33.864659 7ff155ffb700 10 Signature = abbeb6af798b2aad58cd398491698f863253f3859d22b4c9558cc808159d256d
2016-08-18 17:26:33.864660 7ff155ffb700 10 New Signature = e13d83bcd1f52103e9056add844e0037accb71436faee1a3e0048dd6c25cd4b6
2016-08-18 17:26:33.864661 7ff155ffb700 10 -----------------------------
2016-08-18 17:26:33.864664 7ff155ffb700 20 delayed aws4 auth failed
2016-08-18 17:26:33.864674 7ff155ffb700 2 req 624:0.000642:s3:PUT /Photos/Options/BMW/SERIES+1/2012/216/180x102.jpg:put_obj:completing
2016-08-18 17:26:33.864749 7ff155ffb700 2 req 624:0.000717:s3:PUT /Photos/Options/BMW/SERIES+1/2012/216/180x102.jpg:put_obj:op status=-2027
2016-08-18 17:26:33.864757 7ff155ffb700 2 req 624:0.000726:s3:PUT /Photos/Options/BMW/SERIES+1/2012/216/180x102.jpg:put_obj:http status=403
2016-08-18 17:26:33.864762 7ff155ffb700 1 ====== req done req=0x7ff155ff5710 op status=-2027 http_status=403 ======
2016-08-18 17:26:33.864776 7ff155ffb700 20 process_request() returned -2027
2016-08-18 17:26:33.864801 7ff155ffb700 1 civetweb: 0x7ff1f8003e80: 192.168.2.59 - - [18/Aug/2016:17:26:33 +0200] "PUT /Photos/Options/BMW/SERIES+1/2012/216/180x102.jpg HTTP/1.1" 403 0 - -
Updated by Pritha Srivastava over 7 years ago
Jan, Can you provide more details, like steps to reproduce the issue and the exact command that you issued?
Updated by Jan Hugo Prins over 7 years ago
Pritha Srivastava wrote:
Jan, Can you provide more details, like steps to reproduce the issue and the exact command that you issued?
Steps to reproduce:
- Install clean Ceph cluster version 10.2.2
- Install rados gateways.
- Create a bucket
- Create a user with full_controll on the bucket
- Start copying data towards the bucket.
- Some files fail with a signature error.
- The fails that fail in the bulk transfer will also fail when copying separately.
The configuration of my current running cluster:
[root@blsceph01-1 ~]# radosgw-admin realm list
{
"default_info": "f8cdcfe3-238a-4e0d-84c4-d58fada869aa",
"realms": [
"default"
]
}
[root@blsceph01-1 ~]# radosgw-admin zonegroup list
read_default_id : 0
{
"default_info": "d5ad18ed-dfb3-4e4a-a6ee-3c7b4f0cddae",
"zonegroups": [
"default"
]
}
[root@blsceph01-1 ~]# radosgw-admin zone list
{
"default_info": "1adc4b51-3345-4a4b-bf6d-b55b35991530",
"zones": [
"default"
]
}
[root@blsceph01-1 ~]# radosgw-admin realm get
{
"id": "f8cdcfe3-238a-4e0d-84c4-d58fada869aa",
"name": "default",
"current_period": "df62cf41-73e6-4128-ba01-104726754ed7",
"epoch": 2
}
[root@blsceph01-1 ~]# radosgw-admin period list
{
"periods": [
"d825f817-43d1-4ca0-9ca2-0f3946c1e9b7",
"df62cf41-73e6-4128-ba01-104726754ed7",
"f8cdcfe3-238a-4e0d-84c4-d58fada869aa:staging"
]
}
[root@blsceph01-1 ~]# radosgw-admin period get
{
"id": "df62cf41-73e6-4128-ba01-104726754ed7",
"epoch": 4,
"predecessor_uuid": "d825f817-43d1-4ca0-9ca2-0f3946c1e9b7",
"sync_status": [
"",
"",
"",
"",
"",
"",
"",
"",
"",
"",
"",
"",
"",
"",
"",
"",
"",
"",
"",
"",
"",
"",
"",
"",
"",
"",
"",
"",
"",
"",
"",
"",
"",
"",
"",
"",
"",
"",
"",
"",
"",
"",
"",
"",
"",
"",
"",
"",
"",
"",
"",
"",
"",
"",
"",
"",
"",
"",
"",
"",
"",
"",
"",
""
],
"period_map": {
"id": "df62cf41-73e6-4128-ba01-104726754ed7",
"zonegroups": [
{
"id": "d5ad18ed-dfb3-4e4a-a6ee-3c7b4f0cddae",
"name": "default",
"api_name": "",
"is_master": "true",
"endpoints": [],
"hostnames": [],
"hostnames_s3website": [],
"master_zone": "1adc4b51-3345-4a4b-bf6d-b55b35991530",
"zones": [
{
"id": "1adc4b51-3345-4a4b-bf6d-b55b35991530",
"name": "default",
"endpoints": [],
"log_meta": "false",
"log_data": "false",
"bucket_index_max_shards": 0,
"read_only": "false"
}
],
"placement_targets": [
{
"name": "default-placement",
"tags": []
},
{
"name": "dev-placement",
"tags": []
},
{
"name": "nl-demo-placement",
"tags": []
}
],
"default_placement": "default-placement",
"realm_id": "f8cdcfe3-238a-4e0d-84c4-d58fada869aa"
}
],
"short_zone_ids": [
{
"key": "1adc4b51-3345-4a4b-bf6d-b55b35991530",
"val": 588843695
}
]
},
"master_zonegroup": "d5ad18ed-dfb3-4e4a-a6ee-3c7b4f0cddae",
"master_zone": "1adc4b51-3345-4a4b-bf6d-b55b35991530",
"period_config": {
"bucket_quota": {
"enabled": false,
"max_size_kb": -1,
"max_objects": -1
},
"user_quota": {
"enabled": false,
"max_size_kb": -1,
"max_objects": -1
}
},
"realm_id": "f8cdcfe3-238a-4e0d-84c4-d58fada869aa",
"realm_name": "default",
"realm_epoch": 2
}
If you need more information regarding the cluster, just let me know.
The commands used:
s3cmd sync . s3://testbucket/Photos/
s3cmd put "./Options/BMW/SERIES 1/2012/216/180x102.jpg" s3://testbucket/Photos/
Jan Hugo Prins
Updated by Pritha Srivastava over 7 years ago
Jan Hugo Prins wrote:
Pritha Srivastava wrote:
Jan, Can you provide more details, like steps to reproduce the issue and the exact command that you issued?
Steps to reproduce:
- Install clean Ceph cluster version 10.2.2
- Install rados gateways.
- Create a bucket
- Create a user with full_controll on the bucket
- Start copying data towards the bucket.
- Some files fail with a signature error.
- The fails that fail in the bulk transfer will also fail when copying separately.The configuration of my current running cluster:
[root@blsceph01-1 ~]# radosgw-admin realm list {
"default_info": "f8cdcfe3-238a-4e0d-84c4-d58fada869aa",
"realms": [
"default"
]
}[root@blsceph01-1 ~]# radosgw-admin zonegroup list
read_default_id : 0 {
"default_info": "d5ad18ed-dfb3-4e4a-a6ee-3c7b4f0cddae",
"zonegroups": [
"default"
]
}[root@blsceph01-1 ~]# radosgw-admin zone list {
"default_info": "1adc4b51-3345-4a4b-bf6d-b55b35991530",
"zones": [
"default"
]
}[root@blsceph01-1 ~]# radosgw-admin realm get {
"id": "f8cdcfe3-238a-4e0d-84c4-d58fada869aa",
"name": "default",
"current_period": "df62cf41-73e6-4128-ba01-104726754ed7",
"epoch": 2
}[root@blsceph01-1 ~]# radosgw-admin period list {
"periods": [
"d825f817-43d1-4ca0-9ca2-0f3946c1e9b7",
"df62cf41-73e6-4128-ba01-104726754ed7",
"f8cdcfe3-238a-4e0d-84c4-d58fada869aa:staging"
]
}[root@blsceph01-1 ~]# radosgw-admin period get {
"id": "df62cf41-73e6-4128-ba01-104726754ed7",
"epoch": 4,
"predecessor_uuid": "d825f817-43d1-4ca0-9ca2-0f3946c1e9b7",
"sync_status": [
"",
"",
"",
"",
"",
"",
"",
"",
"",
"",
"",
"",
"",
"",
"",
"",
"",
"",
"",
"",
"",
"",
"",
"",
"",
"",
"",
"",
"",
"",
"",
"",
"",
"",
"",
"",
"",
"",
"",
"",
"",
"",
"",
"",
"",
"",
"",
"",
"",
"",
"",
"",
"",
"",
"",
"",
"",
"",
"",
"",
"",
"",
"",
""
],
"period_map": {
"id": "df62cf41-73e6-4128-ba01-104726754ed7",
"zonegroups": [ {
"id": "d5ad18ed-dfb3-4e4a-a6ee-3c7b4f0cddae",
"name": "default",
"api_name": "",
"is_master": "true",
"endpoints": [],
"hostnames": [],
"hostnames_s3website": [],
"master_zone": "1adc4b51-3345-4a4b-bf6d-b55b35991530",
"zones": [ {
"id": "1adc4b51-3345-4a4b-bf6d-b55b35991530",
"name": "default",
"endpoints": [],
"log_meta": "false",
"log_data": "false",
"bucket_index_max_shards": 0,
"read_only": "false"
}
],
"placement_targets": [ {
"name": "default-placement",
"tags": []
}, {
"name": "dev-placement",
"tags": []
}, {
"name": "nl-demo-placement",
"tags": []
}
],
"default_placement": "default-placement",
"realm_id": "f8cdcfe3-238a-4e0d-84c4-d58fada869aa"
}
],
"short_zone_ids": [ {
"key": "1adc4b51-3345-4a4b-bf6d-b55b35991530",
"val": 588843695
}
]
},
"master_zonegroup": "d5ad18ed-dfb3-4e4a-a6ee-3c7b4f0cddae",
"master_zone": "1adc4b51-3345-4a4b-bf6d-b55b35991530",
"period_config": {
"bucket_quota": {
"enabled": false,
"max_size_kb": -1,
"max_objects": -1
},
"user_quota": {
"enabled": false,
"max_size_kb": -1,
"max_objects": -1
}
},
"realm_id": "f8cdcfe3-238a-4e0d-84c4-d58fada869aa",
"realm_name": "default",
"realm_epoch": 2
}If you need more information regarding the cluster, just let me know.
The commands used:
s3cmd sync . s3://testbucket/Photos/
s3cmd put "./Options/BMW/SERIES 1/2012/216/180x102.jpg" s3://testbucket/Photos/Jan Hugo Prins
I have not been able to reproduce the issue, were the files of a particular size, or can you share any other detail that may help me here.
Updated by Jan Hugo Prins over 7 years ago
Pritha Srivastava wrote:
I have not been able to reproduce the issue, were the files of a particular size, or can you share any other detail that may help me here.
What kind of information do you need.
The files is just a set of default files (images and data files) from our production environment.
Nothing special about them.
Today someone send a mail to the user mailinglist with similar issues. In his case he thought it was because of some special character. In my case this is not the issue I think.
The source data is on an Isilon cluster (NFS) and the transfer node I used to test was my laptop (Fedora 23) and a stepstone machine (Fedora 18). I can also try to reproduce the issue using Centos systems.
Jan Hugo
Updated by Jan Hugo Prins over 7 years ago
Jan Hugo Prins wrote:
Pritha Srivastava wrote:
I have not been able to reproduce the issue, were the files of a particular size, or can you share any other detail that may help me here.
What kind of information do you need.
The files is just a set of default files (images and data files) from our production environment.
Nothing special about them.Today someone send a mail to the user mailinglist with similar issues. In his case he thought it was because of some special character. In my case this is not the issue I think.
The source data is on an Isilon cluster (NFS) and the transfer node I used to test was my laptop (Fedora 23) and a stepstone machine (Fedora 18). I can also try to reproduce the issue using Centos systems.
Jan Hugo
Just to test if the problem was not my NFS source, I just used a local source tree and got the following:
upload: 'testdir/data1/Adobe Flex Builder 2.0.1/ColdFusion Extensions for Flex Builder/CF_FB_Extensions.zip' -> 's3://testbucket/Adobe Flex Builder 2.0.1/ColdFusion Extensions for Flex Builder/CF_FB_Extensions.zip' [9 of 41537]
12109555 of 12109555 100% in 0s 30.14 MB/s done
ERROR: S3 error: 403 (SignatureDoesNotMatch)
[jprins@stepstone01 ~]$
Can you please run s3cmd with --debug option and then post the debug logs alongwith the rgw logs? That may help in understanding what is going wrong there.
Updated by Pritha Srivastava over 7 years ago
Jan Hugo Prins wrote:
Jan Hugo Prins wrote:
Pritha Srivastava wrote:
I have not been able to reproduce the issue, were the files of a particular size, or can you share any other detail that may help me here.
What kind of information do you need.
The files is just a set of default files (images and data files) from our production environment.
Nothing special about them.Today someone send a mail to the user mailinglist with similar issues. In his case he thought it was because of some special character. In my case this is not the issue I think.
The source data is on an Isilon cluster (NFS) and the transfer node I used to test was my laptop (Fedora 23) and a stepstone machine (Fedora 18). I can also try to reproduce the issue using Centos systems.
Jan Hugo
Just to test if the problem was not my NFS source, I just used a local source tree and got the following:
upload: 'testdir/data1/Adobe Flex Builder 2.0.1/ColdFusion Extensions for Flex Builder/CF_FB_Extensions.zip' -> 's3://testbucket/Adobe Flex Builder 2.0.1/ColdFusion Extensions for Flex Builder/CF_FB_Extensions.zip' [9 of 41537]
12109555 of 12109555 100% in 0s 30.14 MB/s done
ERROR: S3 error: 403 (SignatureDoesNotMatch)
[jprins@stepstone
Based on the logs received from Jan, can see that space in the path 'Adobe Flex Builder 2.0.1/ColdFusion Extensions for Flex Builder/' is encoded as %20 in s3cmd and as '+' in rgwlogs.
s3cmdlogs
---------
DEBUG: Canonical Request:
PUT
/Adobe%20Flex%20Builder%202.0.1/ColdFusion%20Extensions%20for%20Flex%20Builder/CF_FB_Extensions.zip
content-length:12109555
content-type:application/zip
rgwlogs
--------
canonical request = PUT
/Adobe+Flex+Builder+2.0.1/ColdFusion+Extensions+for+Flex+Builder/CF_FB_Extensions.zip
content-length:12109555
content-type:application/zip
I was also able to repro the issue by inserting a space in the file name.
Updated by Pritha Srivastava over 7 years ago
s3cmd encodes space as "%20" while computing signature whereas it encodes space as "+" while passing the canonical uri to rgw. rgw uses this canonical uri to compute the signature at its end, which results in a SignatureMismatch error. I have a tentative fix which replaces '+' with "%20" in the canonical uri, which solves the issue:
https://github.com/ceph/ceph/pull/10919
I have also raised this issue with s3cmd developers and we can wait till we hear back from them.
Note: Boto2 doesn't have this issue.They are consistently using "%20" everywhere. The Amazon docs also clearly says that space should be encoded as "%20": http://docs.aws.amazon.com/general/latest/gr/sigv4-create-canonical-request.html
Updated by Luis Periquito over 7 years ago
I'm using s3cmd 1.6.1 (as it comes in Xenial). As server I have 10.2.2, both installed initially as Jewel and upgraded from Hammer/Giant.
All works fine with s3cmd 1.1 (as it comes in Trusty), and s3cmd 1.6 with the option "--signature-v2".
Upload, both multipart or not, works fine.
Download and sync always fails. My files have no spaces in them, and I haven't tested against amazon AWS.
This is what I get from running radosgw with "-d --debug-rgw=20"
2016-09-16 09:18:23.799090 7fd5c7f87700 20 enqueued request req=0x7fd62c0212a0
2016-09-16 09:18:23.799101 7fd5c7f87700 20 RGWWQ:
2016-09-16 09:18:23.799103 7fd5c7f87700 20 req: 0x7fd62c0212a0
2016-09-16 09:18:23.799108 7fd5c7f87700 10 allocated request req=0x7fd62c022a10
2016-09-16 09:18:23.799137 7fd5c4780700 20 dequeued request req=0x7fd62c0212a0
2016-09-16 09:18:23.799142 7fd5c4780700 20 RGWWQ: empty
2016-09-16 09:18:23.799172 7fd5c4780700 20 CONTENT_LENGTH=0
2016-09-16 09:18:23.799177 7fd5c4780700 20 CONTEXT_DOCUMENT_ROOT=/var/lib/ceph/radosgw/stratus-el02sv20/htdocs/
2016-09-16 09:18:23.799177 7fd5c4780700 20 CONTEXT_PREFIX=
2016-09-16 09:18:23.799178 7fd5c4780700 20 DOCUMENT_ROOT=/var/lib/ceph/radosgw/stratus-el02sv20/htdocs/
2016-09-16 09:18:23.799178 7fd5c4780700 20 FCGI_ROLE=RESPONDER
2016-09-16 09:18:23.799179 7fd5c4780700 20 GATEWAY_INTERFACE=CGI/1.1
2016-09-16 09:18:23.799179 7fd5c4780700 20 HTTP_ACCEPT_ENCODING=identity
2016-09-16 09:18:23.799179 7fd5c4780700 20 HTTP_AUTHORIZATION=AWS4-HMAC-SHA256 Credential=C0K66XRJC2NW0O0WN06U/20160916/US/s3/aws4_request,SignedHeaders=host;x-amz-content-sha256;x-amz-date,Signature=ffba2fed4bb82f44e1cf2ba78453e7b64a5523e4031a4bd746aeaaf3b79aab55
2016-09-16 09:18:23.799181 7fd5c4780700 20 HTTP_HOST=luis.s3stratus.inflab.ocado.com
2016-09-16 09:18:23.799181 7fd5c4780700 20 HTTP_X_AMZ_CONTENT_SHA256=e3b0c44298fc1c149afbf4c8996fb92427ae41e4649b934ca495991b7852b855
2016-09-16 09:18:23.799182 7fd5c4780700 20 HTTP_X_AMZ_DATE=20160916T081823Z
2016-09-16 09:18:23.799182 7fd5c4780700 20 PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin
2016-09-16 09:18:23.799183 7fd5c4780700 20 QUERY_STRING=page=¶ms=&prefix=.
2016-09-16 09:18:23.799183 7fd5c4780700 20 REMOTE_ADDR=10.252.24.104
2016-09-16 09:18:23.799183 7fd5c4780700 20 REMOTE_PORT=51522
2016-09-16 09:18:23.799184 7fd5c4780700 20 REQUEST_METHOD=GET
2016-09-16 09:18:23.799184 7fd5c4780700 20 REQUEST_SCHEME=http
2016-09-16 09:18:23.799185 7fd5c4780700 20 REQUEST_URI=/?prefix=.
2016-09-16 09:18:23.799185 7fd5c4780700 20 SCRIPT_FILENAME=/var/lib/ceph/radosgw/stratus-el02sv20/htdocs/s3gw
2016-09-16 09:18:23.799185 7fd5c4780700 20 SCRIPT_NAME=/
2016-09-16 09:18:23.799186 7fd5c4780700 20 SCRIPT_URI=http://luis.s3stratus.inflab.ocado.com/
2016-09-16 09:18:23.799186 7fd5c4780700 20 SCRIPT_URL=/
2016-09-16 09:18:23.799195 7fd5c4780700 20 SERVER_ADDR=10.64.134.16
2016-09-16 09:18:23.799195 7fd5c4780700 20 SERVER_ADMIN=[no address given]
2016-09-16 09:18:23.799196 7fd5c4780700 20 SERVER_NAME=luis.s3stratus.inflab.ocado.com
2016-09-16 09:18:23.799196 7fd5c4780700 20 SERVER_PORT=80
2016-09-16 09:18:23.799196 7fd5c4780700 20 SERVER_PROTOCOL=HTTP/1.1
2016-09-16 09:18:23.799197 7fd5c4780700 20 SERVER_SIGNATURE=
2016-09-16 09:18:23.799197 7fd5c4780700 20 SERVER_SOFTWARE=Apache/2.4.7 (Ubuntu)
2016-09-16 09:18:23.799200 7fd5c4780700 1 ====== starting new request req=0x7fd62c0212a0 =====
2016-09-16 09:18:23.799223 7fd5c4780700 2 req 1:0.000023::GET /::initializing for trans_id = tx000000000000000000001-0057dbaacf-1dd797-default
2016-09-16 09:18:23.799227 7fd5c4780700 10 host=luis.s3stratus.inflab.ocado.com
2016-09-16 09:18:23.799233 7fd5c4780700 20 subdomain=luis domain=s3stratus.inflab.ocado.com in_hosted_domain=1 in_hosted_domain_s3website=0
2016-09-16 09:18:23.799243 7fd5c4780700 10 meta>> HTTP_X_AMZ_CONTENT_SHA256
2016-09-16 09:18:23.799247 7fd5c4780700 10 meta>> HTTP_X_AMZ_DATE
2016-09-16 09:18:23.799250 7fd5c4780700 10 x>> x-amz-content-sha256:e3b0c44298fc1c149afbf4c8996fb92427ae41e4649b934ca495991b7852b855
2016-09-16 09:18:23.799251 7fd5c4780700 10 x>> x-amz-date:20160916T081823Z
2016-09-16 09:18:23.799273 7fd5c4780700 20 get_handler handler=25RGWHandler_REST_Bucket_S3
2016-09-16 09:18:23.799278 7fd5c4780700 10 handler=25RGWHandler_REST_Bucket_S3
2016-09-16 09:18:23.799279 7fd5c4780700 2 req 1:0.000079:s3:GET /::getting op 0
2016-09-16 09:18:23.799289 7fd5c4780700 10 op=25RGWListBucket_ObjStore_S3
2016-09-16 09:18:23.799290 7fd5c4780700 2 req 1:0.000090:s3:GET /:list_bucket:authorizing
2016-09-16 09:18:23.799298 7fd5c4780700 10 v4 signedheaders format = host;x-amz-content-sha256;x-amz-date
2016-09-16 09:18:23.799302 7fd5c4780700 10 v4 signature format = ffba2fed4bb82f44e1cf2ba78453e7b64a5523e4031a4bd746aeaaf3b79aab55
2016-09-16 09:18:23.799313 7fd5c4780700 10 v4 credential format = C0K66XRJC2NW0O0WN06U/20160916/US/s3/aws4_request
2016-09-16 09:18:23.799315 7fd5c4780700 10 access key id = C0K66XRJC2NW0O0WN06U
2016-09-16 09:18:23.799316 7fd5c4780700 10 credential scope = 20160916/US/s3/aws4_request
2016-09-16 09:18:23.799333 7fd5c4780700 20 get_system_obj_state: rctx=0x7fd5c477d4f0 obj=.users:C0K66XRJC2NW0O0WN06U state=0x7fd644013f68 s->prefetch_data=0
2016-09-16 09:18:23.799338 7fd5c4780700 10 cache get: name=.users+C0K66XRJC2NW0O0WN06U : miss
2016-09-16 09:18:23.800192 7fd5c4780700 10 cache put: name=.users+C0K66XRJC2NW0O0WN06U info.flags=6
2016-09-16 09:18:23.800203 7fd5c4780700 10 adding .users+C0K66XRJC2NW0O0WN06U to cache LRU end
2016-09-16 09:18:23.800207 7fd5c4780700 20 get_system_obj_state: s->obj_tag was set empty
2016-09-16 09:18:23.800211 7fd5c4780700 10 cache get: name=.users+C0K66XRJC2NW0O0WN06U : type miss (requested=1, cached=6)
2016-09-16 09:18:23.800214 7fd5c4780700 20 get_system_obj_state: rctx=0x7fd5c477d4f0 obj=.users:C0K66XRJC2NW0O0WN06U state=0x7fd644013f68 s->prefetch_data=0
2016-09-16 09:18:23.800216 7fd5c4780700 20 rados->read ofs=0 len=524288
2016-09-16 09:18:23.800865 7fd5c4780700 20 rados->read r=0 bl.length=8
2016-09-16 09:18:23.800885 7fd5c4780700 10 cache put: name=.users+C0K66XRJC2NW0O0WN06U info.flags=1
2016-09-16 09:18:23.800887 7fd5c4780700 10 moving .users+C0K66XRJC2NW0O0WN06U to cache LRU end
2016-09-16 09:18:23.800901 7fd5c4780700 20 get_system_obj_state: rctx=0x7fd5c477d010 obj=.users.uid:luis state=0x7fd644015b58 s->prefetch_data=0
2016-09-16 09:18:23.800908 7fd5c4780700 10 cache get: name=.users.uid+luis : miss
2016-09-16 09:18:23.801404 7fd5c4780700 10 cache put: name=.users.uid+luis info.flags=22
2016-09-16 09:18:23.801410 7fd5c4780700 10 adding .users.uid+luis to cache LRU end
2016-09-16 09:18:23.801413 7fd5c4780700 20 get_system_obj_state: s->obj_tag was set empty
2016-09-16 09:18:23.801416 7fd5c4780700 10 cache get: name=.users.uid+luis : type miss (requested=17, cached=22)
2016-09-16 09:18:23.801418 7fd5c4780700 20 get_system_obj_state: rctx=0x7fd5c477d010 obj=.users.uid:luis state=0x7fd644015b58 s->prefetch_data=0
2016-09-16 09:18:23.801439 7fd5c4780700 20 rados->read ofs=0 len=524288
2016-09-16 09:18:23.801793 7fd5c4780700 20 rados->read r=0 bl.length=320
2016-09-16 09:18:23.801803 7fd5c4780700 10 cache put: name=.users.uid+luis info.flags=17
2016-09-16 09:18:23.801805 7fd5c4780700 10 moving .users.uid+luis to cache LRU end
2016-09-16 09:18:23.801832 7fd5c4780700 10 chain_cache_entry: cache_locator=.users.uid+luis
2016-09-16 09:18:23.801870 7fd5c4780700 10 canonical headers format = host:luis.s3stratus.inflab.ocado.com
x-amz-content-sha256:e3b0c44298fc1c149afbf4c8996fb92427ae41e4649b934ca495991b7852b855
x-amz-date:20160916T081823Z
2016-09-16 09:18:23.801897 7fd5c4780700 10 payload request hash = e3b0c44298fc1c149afbf4c8996fb92427ae41e4649b934ca495991b7852b855
2016-09-16 09:18:23.801908 7fd5c4780700 10 canonical request = GET
/
prefix=.
host:luis.s3stratus.inflab.ocado.com
x-amz-content-sha256:e3b0c44298fc1c149afbf4c8996fb92427ae41e4649b934ca495991b7852b855
x-amz-date:20160916T081823Z
host;x-amz-content-sha256;x-amz-date
e3b0c44298fc1c149afbf4c8996fb92427ae41e4649b934ca495991b7852b855
2016-09-16 09:18:23.801911 7fd5c4780700 10 canonical request hash = bf02e42eba3ad2bda2f03ed3801956c5df3bae08de48daa9ecded316ea1a9640
2016-09-16 09:18:23.801913 7fd5c4780700 10 string to sign = AWS4-HMAC-SHA256
20160916T081823Z
20160916/US/s3/aws4_request
bf02e42eba3ad2bda2f03ed3801956c5df3bae08de48daa9ecded316ea1a9640
2016-09-16 09:18:23.801953 7fd5c4780700 10 date_k = 5de0fe6cbbd1c7f0cbae1b9123e0df1300de69e86cce88bb9b2aab2837dd1fee
2016-09-16 09:18:23.801970 7fd5c4780700 10 region_k = 8d598fb8a0cd5658cce911790d8f7295c1b80a975cbc7cc20bf8fc0d92701ed8
2016-09-16 09:18:23.801986 7fd5c4780700 10 service_k = 06f9337b2ddcd0ef62f3c5bb898f1e79653a13db810580873e69bb85516260f1
2016-09-16 09:18:23.802000 7fd5c4780700 10 signing_k = 3e60b563bb70c72120462681bbaed28e67a63aae268f748980f4c4fa4b5d0a6d
2016-09-16 09:18:23.802015 7fd5c4780700 10 signature_k = ffba2fed4bb82f44e1cf2ba78453e7b64a5523e4031a4bd746aeaaf3b79aab55
2016-09-16 09:18:23.802017 7fd5c4780700 10 new signature = ffba2fed4bb82f44e1cf2ba78453e7b64a5523e4031a4bd746aeaaf3b79aab55
2016-09-16 09:18:23.802018 7fd5c4780700 10 ----------------------------- Verifying signatures
2016-09-16 09:18:23.802019 7fd5c4780700 10 Signature = ffba2fed4bb82f44e1cf2ba78453e7b64a5523e4031a4bd746aeaaf3b79aab55
2016-09-16 09:18:23.802020 7fd5c4780700 10 New Signature = ffba2fed4bb82f44e1cf2ba78453e7b64a5523e4031a4bd746aeaaf3b79aab55
2016-09-16 09:18:23.802020 7fd5c4780700 10 -----------------------------
2016-09-16 09:18:23.802022 7fd5c4780700 10 v4 auth ok
2016-09-16 09:18:23.802025 7fd5c4780700 2 req 1:0.002825:s3:GET /:list_bucket:normalizing buckets and tenants
2016-09-16 09:18:23.802029 7fd5c4780700 10 s->object=<NULL> s->bucket=luis
2016-09-16 09:18:23.802033 7fd5c4780700 2 req 1:0.002833:s3:GET /:list_bucket:init permissions
2016-09-16 09:18:23.802046 7fd5c4780700 20 get_system_obj_state: rctx=0x7fd5c477e710 obj=.rgw:luis state=0x7fd64401bfe8 s->prefetch_data=0
2016-09-16 09:18:23.802059 7fd5c4780700 10 cache get: name=.rgw+luis : miss
2016-09-16 09:18:23.802914 7fd5c4780700 10 cache put: name=.rgw+luis info.flags=22
2016-09-16 09:18:23.802919 7fd5c4780700 10 adding .rgw+luis to cache LRU end
2016-09-16 09:18:23.802922 7fd5c4780700 20 get_system_obj_state: s->obj_tag was set empty
2016-09-16 09:18:23.802924 7fd5c4780700 20 Read xattr: user.rgw.idtag
2016-09-16 09:18:23.802925 7fd5c4780700 20 Read xattr: user.rgw.manifest
2016-09-16 09:18:23.802927 7fd5c4780700 10 cache get: name=.rgw+luis : type miss (requested=17, cached=22)
2016-09-16 09:18:23.802929 7fd5c4780700 20 get_system_obj_state: rctx=0x7fd5c477e710 obj=.rgw:luis state=0x7fd64401bfe8 s->prefetch_data=0
2016-09-16 09:18:23.802941 7fd5c4780700 20 rados->read ofs=0 len=524288
2016-09-16 09:18:23.803507 7fd5c4780700 20 rados->read r=0 bl.length=139
2016-09-16 09:18:23.803512 7fd5c4780700 10 cache put: name=.rgw+luis info.flags=17
2016-09-16 09:18:23.803513 7fd5c4780700 10 moving .rgw+luis to cache LRU end
2016-09-16 09:18:23.803519 7fd5c4780700 20 rgw_get_bucket_info: bucket instance: luis({i=.rgw.buckets.index,e=.rgw.buckets.extra}.rgw.buckets[default.1330123.1]){i=.rgw.buckets.index,e=.rgw.buckets.extra}.rgw.buckets[default.1330123.1]) start [] num_entries 1001
2016-09-16 09:18:23.803526 7fd5c4780700 20 reading from .rgw:.bucket.meta.luis:default.1330123.1
2016-09-16 09:18:23.803530 7fd5c4780700 20 get_system_obj_state: rctx=0x7fd5c477e710 obj=.rgw:.bucket.meta.luis:default.1330123.1 state=0x7fd64401ec48 s->prefetch_data=0
2016-09-16 09:18:23.803533 7fd5c4780700 10 cache get: name=.rgw+.bucket.meta.luis:default.1330123.1 : miss
2016-09-16 09:18:23.803894 7fd5c4780700 10 cache put: name=.rgw+.bucket.meta.luis:default.1330123.1 info.flags=22
2016-09-16 09:18:23.803902 7fd5c4780700 10 adding .rgw+.bucket.meta.luis:default.1330123.1 to cache LRU end
2016-09-16 09:18:23.803903 7fd5c4780700 10 updating xattr: name=user.rgw.acl bl.length()=141
2016-09-16 09:18:23.803906 7fd5c4780700 20 get_system_obj_state: s->obj_tag was set empty
2016-09-16 09:18:23.803907 7fd5c4780700 20 Read xattr: user.rgw.acl
2016-09-16 09:18:23.803907 7fd5c4780700 20 Read xattr: user.rgw.idtag
2016-09-16 09:18:23.803908 7fd5c4780700 20 Read xattr: user.rgw.manifest
2016-09-16 09:18:23.803910 7fd5c4780700 10 cache get: name=.rgw+.bucket.meta.luis:default.1330123.1 : type miss (requested=17, cached=22)
2016-09-16 09:18:23.803913 7fd5c4780700 20 get_system_obj_state: rctx=0x7fd5c477e710 obj=.rgw:.bucket.meta.luis:default.1330123.1 state=0x7fd64401ec48 s->prefetch_data=0
2016-09-16 09:18:23.803927 7fd5c4780700 20 rados->read ofs=0 len=524288
2016-09-16 09:18:23.804191 7fd5c4780700 20 rados->read r=0 bl.length=203
2016-09-16 09:18:23.804198 7fd5c4780700 10 cache put: name=.rgw+.bucket.meta.luis:default.1330123.1 info.flags=17
2016-09-16 09:18:23.804200 7fd5c4780700 10 moving .rgw+.bucket.meta.luis:default.1330123.1 to cache LRU end
2016-09-16 09:18:23.804211 7fd5c4780700 10 chain_cache_entry: cache_locator=.rgw+luis
2016-09-16 09:18:23.804214 7fd5c4780700 10 chain_cache_entry: cache_locator=.rgw+.bucket.meta.luis:default.1330123.1
2016-09-16 09:18:23.804233 7fd5c4780700 15 decode_policy Read AccessControlPolicy<AccessControlPolicy xmlns="http://s3.amazonaws.com/doc/2006-03-01/"><Owner><ID>luis</ID><DisplayName>luis test user</DisplayName></Owner><AccessControlList><Grant><Grantee xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance" xsi:type="CanonicalUser"><ID>luis</ID><DisplayName>luis test user</DisplayName></Grantee><Permission>FULL_CONTROL</Permission></Grant></AccessControlList></AccessControlPolicy>
2016-09-16 09:18:23.804247 7fd5c4780700 2 req 1:0.005047:s3:GET /:list_bucket:recalculating target
2016-09-16 09:18:23.804251 7fd5c4780700 2 req 1:0.005051:s3:GET /:list_bucket:reading permissions
2016-09-16 09:18:23.804254 7fd5c4780700 2 req 1:0.005054:s3:GET /:list_bucket:init op
2016-09-16 09:18:23.804257 7fd5c4780700 2 req 1:0.005057:s3:GET /:list_bucket:verifying op mask
2016-09-16 09:18:23.804259 7fd5c4780700 20 required_mask= 1 user.op_mask=7
2016-09-16 09:18:23.804260 7fd5c4780700 2 req 1:0.005060:s3:GET /:list_bucket:verifying op permissions
2016-09-16 09:18:23.804263 7fd5c4780700 5 Searching permissions for uid=luis mask=49
2016-09-16 09:18:23.804265 7fd5c4780700 5 Found permission: 15
2016-09-16 09:18:23.804266 7fd5c4780700 5 Searching permissions for group=1 mask=49
2016-09-16 09:18:23.804266 7fd5c4780700 5 Permissions for group not found
2016-09-16 09:18:23.804267 7fd5c4780700 5 Searching permissions for group=2 mask=49
2016-09-16 09:18:23.804268 7fd5c4780700 5 Permissions for group not found
2016-09-16 09:18:23.804268 7fd5c4780700 5 Getting permissions id=luis owner=luis perm=1
2016-09-16 09:18:23.804269 7fd5c4780700 10 uid=luis requested perm (type)=1, policy perm=1, user_perm_mask=1, acl perm=1
2016-09-16 09:18:23.804270 7fd5c4780700 2 req 1:0.005070:s3:GET /:list_bucket:verifying op params
2016-09-16 09:18:23.804271 7fd5c4780700 2 req 1:0.005071:s3:GET /:list_bucket:pre-executing
2016-09-16 09:18:23.804273 7fd5c4780700 2 req 1:0.005073:s3:GET /:list_bucket:executing
2016-09-16 09:18:23.804285 7fd5c4780700 10 cls_bucket_list luis(
2016-09-16 09:18:23.804294 7fd5c4780700 20 reading from .rgw:.bucket.meta.luis:default.1330123.1
2016-09-16 09:18:23.804298 7fd5c4780700 20 get_system_obj_state: rctx=0x7fd5c477d080 obj=.rgw:.bucket.meta.luis:default.1330123.1 state=0x7fd644023768 s->prefetch_data=0
2016-09-16 09:18:23.804301 7fd5c4780700 10 cache get: name=.rgw+.bucket.meta.luis:default.1330123.1 : type miss (requested=22, cached=19)
2016-09-16 09:18:23.804553 7fd5c4780700 10 cache put: name=.rgw+.bucket.meta.luis:default.1330123.1 info.flags=22
2016-09-16 09:18:23.804559 7fd5c4780700 10 moving .rgw+.bucket.meta.luis:default.1330123.1 to cache LRU end
2016-09-16 09:18:23.804560 7fd5c4780700 10 updating xattr: name=user.rgw.acl bl.length()=141
2016-09-16 09:18:23.804563 7fd5c4780700 20 get_system_obj_state: s->obj_tag was set empty
2016-09-16 09:18:23.804565 7fd5c4780700 10 cache get: name=.rgw+.bucket.meta.luis:default.1330123.1 : hit (requested=17, cached=23)
2016-09-16 09:18:23.805146 7fd5c4780700 2 req 1:0.005946:s3:GET /:list_bucket:completing
2016-09-16 09:18:23.805182 7fd5c4780700 2 req 1:0.005982:s3:GET /:list_bucket:op status=0
2016-09-16 09:18:23.805185 7fd5c4780700 2 req 1:0.005985:s3:GET /:list_bucket:http status=200
2016-09-16 09:18:23.805192 7fd5c4780700 1 ====== req done req=0x7fd62c0212a0 op status=0 http_status=200 ======
2016-09-16 09:18:23.815953 7fd5c7f87700 20 enqueued request req=0x7fd62c022a10
2016-09-16 09:18:23.815964 7fd5c7f87700 20 RGWWQ:
2016-09-16 09:18:23.815966 7fd5c7f87700 20 req: 0x7fd62c022a10
2016-09-16 09:18:23.815970 7fd5c7f87700 10 allocated request req=0x7fd62c022230
2016-09-16 09:18:23.816001 7fd5c4f81700 20 dequeued request req=0x7fd62c022a10
2016-09-16 09:18:23.816005 7fd5c4f81700 20 RGWWQ: empty
2016-09-16 09:18:23.816047 7fd5c4f81700 20 CONTENT_LENGTH=1354
2016-09-16 09:18:23.816052 7fd5c4f81700 20 CONTENT_TYPE=text/plain
2016-09-16 09:18:23.816052 7fd5c4f81700 20 CONTEXT_DOCUMENT_ROOT=/var/lib/ceph/radosgw/stratus-el02sv20/htdocs/
2016-09-16 09:18:23.816053 7fd5c4f81700 20 CONTEXT_PREFIX=
2016-09-16 09:18:23.816053 7fd5c4f81700 20 DOCUMENT_ROOT=/var/lib/ceph/radosgw/stratus-el02sv20/htdocs/
2016-09-16 09:18:23.816054 7fd5c4f81700 20 FCGI_ROLE=RESPONDER
2016-09-16 09:18:23.816056 7fd5c4f81700 20 GATEWAY_INTERFACE=CGI/1.1
2016-09-16 09:18:23.816056 7fd5c4f81700 20 HTTP_ACCEPT_ENCODING=identity
2016-09-16 09:18:23.816057 7fd5c4f81700 20 HTTP_AUTHORIZATION=AWS4-HMAC-SHA256 Credential=C0K66XRJC2NW0O0WN06U/20160916/US/s3/aws4_request,SignedHeaders=content-length;content-type;host;x-amz-content-sha256;x-amz-date;x-amz-meta-s3cmd-attrs;x-amz-storage-class,Signature=6845cb459d6ec0c4770318f5948ed2c216d97776c13154ab9b041283df74b692
2016-09-16 09:18:23.816058 7fd5c4f81700 20 HTTP_HOST=luis.s3stratus.inflab.ocado.com
2016-09-16 09:18:23.816059 7fd5c4f81700 20 HTTP_X_AMZ_CONTENT_SHA256=b18765bc05bf77dd750cd05e57195081222a211b0e3ec4637be54756d71de979
2016-09-16 09:18:23.816059 7fd5c4f81700 20 HTTP_X_AMZ_DATE=20160916T081823Z
2016-09-16 09:18:23.816059 7fd5c4f81700 20 HTTP_X_AMZ_META_S3CMD_ATTRS=uid:1000/gname:luis/uname:luis/gid:1000/mode:33152/mtime:1474013666/atime:1474013678/md5:e9aee935aba54366ec3cf58869e598dc/ctime:1474013666
2016-09-16 09:18:23.816060 7fd5c4f81700 20 HTTP_X_AMZ_STORAGE_CLASS=STANDARD
2016-09-16 09:18:23.816060 7fd5c4f81700 20 PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin
2016-09-16 09:18:23.816061 7fd5c4f81700 20 QUERY_STRING=page=s3cfg_stratus¶ms=
2016-09-16 09:18:23.816061 7fd5c4f81700 20 REMOTE_ADDR=10.252.24.104
2016-09-16 09:18:23.816062 7fd5c4f81700 20 REMOTE_PORT=51523
2016-09-16 09:18:23.816062 7fd5c4f81700 20 REQUEST_METHOD=PUT
2016-09-16 09:18:23.816063 7fd5c4f81700 20 REQUEST_SCHEME=http
2016-09-16 09:18:23.816064 7fd5c4f81700 20 REQUEST_URI=/s3cfg_stratus
2016-09-16 09:18:23.816064 7fd5c4f81700 20 SCRIPT_FILENAME=/var/lib/ceph/radosgw/stratus-el02sv20/htdocs/s3gw
2016-09-16 09:18:23.816065 7fd5c4f81700 20 SCRIPT_NAME=/s3cfg_stratus
2016-09-16 09:18:23.816065 7fd5c4f81700 20 SCRIPT_URI=http://luis.s3stratus.inflab.ocado.com/s3cfg_stratus
2016-09-16 09:18:23.816065 7fd5c4f81700 20 SCRIPT_URL=/s3cfg_stratus
2016-09-16 09:18:23.816066 7fd5c4f81700 20 SERVER_ADDR=10.64.134.16
2016-09-16 09:18:23.816066 7fd5c4f81700 20 SERVER_ADMIN=[no address given]
2016-09-16 09:18:23.816066 7fd5c4f81700 20 SERVER_NAME=luis.s3stratus.inflab.ocado.com
2016-09-16 09:18:23.816067 7fd5c4f81700 20 SERVER_PORT=80
2016-09-16 09:18:23.816067 7fd5c4f81700 20 SERVER_PROTOCOL=HTTP/1.1
2016-09-16 09:18:23.816067 7fd5c4f81700 20 SERVER_SIGNATURE=
2016-09-16 09:18:23.816068 7fd5c4f81700 20 SERVER_SOFTWARE=Apache/2.4.7 (Ubuntu)
2016-09-16 09:18:23.816068 7fd5c4f81700 1 ====== starting new request req=0x7fd62c022a10 =====
2016-09-16 09:18:23.816077 7fd5c4f81700 2 req 2:0.000008::PUT /s3cfg_stratus::initializing for trans_id = tx000000000000000000002-0057dbaacf-1dd797-default
2016-09-16 09:18:23.816080 7fd5c4f81700 10 host=luis.s3stratus.inflab.ocado.com
2016-09-16 09:18:23.816083 7fd5c4f81700 20 subdomain=luis domain=s3stratus.inflab.ocado.com in_hosted_domain=1 in_hosted_domain_s3website=0
2016-09-16 09:18:23.816091 7fd5c4f81700 10 meta>> HTTP_X_AMZ_CONTENT_SHA256
2016-09-16 09:18:23.816093 7fd5c4f81700 10 meta>> HTTP_X_AMZ_DATE
2016-09-16 09:18:23.816094 7fd5c4f81700 10 meta>> HTTP_X_AMZ_META_S3CMD_ATTRS
2016-09-16 09:18:23.816096 7fd5c4f81700 10 meta>> HTTP_X_AMZ_STORAGE_CLASS
2016-09-16 09:18:23.816098 7fd5c4f81700 10 x>> x-amz-content-sha256:b18765bc05bf77dd750cd05e57195081222a211b0e3ec4637be54756d71de979
2016-09-16 09:18:23.816099 7fd5c4f81700 10 x>> x-amz-date:20160916T081823Z
2016-09-16 09:18:23.816099 7fd5c4f81700 10 x>> x-amz-meta-s3cmd-attrs:uid:1000/gname:luis/uname:luis/gid:1000/mode:33152/mtime:1474013666/atime:1474013678/md5:e9aee935aba54366ec3cf58869e598dc/ctime:1474013666
2016-09-16 09:18:23.816100 7fd5c4f81700 10 x>> x-amz-storage-class:STANDARD
2016-09-16 09:18:23.816121 7fd5c4f81700 20 get_handler handler=22RGWHandler_REST_Obj_S3
2016-09-16 09:18:23.816123 7fd5c4f81700 10 handler=22RGWHandler_REST_Obj_S3
2016-09-16 09:18:23.816124 7fd5c4f81700 2 req 2:0.000056:s3:PUT /s3cfg_stratus::getting op 1
2016-09-16 09:18:23.816128 7fd5c4f81700 10 op=21RGWPutObj_ObjStore_S3
2016-09-16 09:18:23.816129 7fd5c4f81700 2 req 2:0.000061:s3:PUT /s3cfg_stratus:put_obj:authorizing
2016-09-16 09:18:23.816133 7fd5c4f81700 10 v4 signedheaders format = content-length;content-type;host;x-amz-content-sha256;x-amz-date;x-amz-meta-s3cmd-attrs;x-amz-storage-class
2016-09-16 09:18:23.816136 7fd5c4f81700 10 v4 signature format = 6845cb459d6ec0c4770318f5948ed2c216d97776c13154ab9b041283df74b692
2016-09-16 09:18:23.816139 7fd5c4f81700 10 v4 credential format = C0K66XRJC2NW0O0WN06U/20160916/US/s3/aws4_request
2016-09-16 09:18:23.816140 7fd5c4f81700 10 access key id = C0K66XRJC2NW0O0WN06U
2016-09-16 09:18:23.816141 7fd5c4f81700 10 credential scope = 20160916/US/s3/aws4_request
2016-09-16 09:18:23.816164 7fd5c4f81700 10 canonical headers format = content-length:1354
content-type:text/plain
host:luis.s3stratus.inflab.ocado.com
x-amz-content-sha256:b18765bc05bf77dd750cd05e57195081222a211b0e3ec4637be54756d71de979
x-amz-date:20160916T081823Z
x-amz-meta-s3cmd-attrs:uid:1000/gname:luis/uname:luis/gid:1000/mode:33152/mtime:1474013666/atime:1474013678/md5:e9aee935aba54366ec3cf58869e598dc/ctime:1474013666
x-amz-storage-class:STANDARD
2016-09-16 09:18:23.816166 7fd5c4f81700 10 body content detected... delaying v4 auth
2016-09-16 09:18:23.816168 7fd5c4f81700 2 req 2:0.000099:s3:PUT /s3cfg_stratus:put_obj:normalizing buckets and tenants
2016-09-16 09:18:23.816169 7fd5c4f81700 10 s->object=s3cfg_stratus s->bucket=luis
2016-09-16 09:18:23.816170 7fd5c4f81700 2 req 2:0.000101:s3:PUT /s3cfg_stratus:put_obj:init permissions
2016-09-16 09:18:23.816176 7fd5c4f81700 20 get_system_obj_state: rctx=0x7fd5c4f7f710 obj=.rgw:luis state=0x7fd6380166b8 s->prefetch_data=0
2016-09-16 09:18:23.816179 7fd5c4f81700 10 cache get: name=.rgw+luis : type miss (requested=22, cached=19)
2016-09-16 09:18:23.816923 7fd5c4f81700 10 cache put: name=.rgw+luis info.flags=22
2016-09-16 09:18:23.816931 7fd5c4f81700 10 moving .rgw+luis to cache LRU end
2016-09-16 09:18:23.816935 7fd5c4f81700 20 get_system_obj_state: s->obj_tag was set empty
2016-09-16 09:18:23.816945 7fd5c4f81700 20 Read xattr: user.rgw.idtag
2016-09-16 09:18:23.816946 7fd5c4f81700 20 Read xattr: user.rgw.manifest
2016-09-16 09:18:23.816948 7fd5c4f81700 10 cache get: name=.rgw+luis : hit (requested=17, cached=23)
2016-09-16 09:18:23.816956 7fd5c4f81700 20 rgw_get_bucket_info: bucket instance: luis(@{i=.rgw.buckets.index,e=.rgw.buckets.extra}.rgw.buckets[default.1330123.1])
2016-09-16 09:18:23.816959 7fd5c4f81700 20 reading from .rgw:.bucket.meta.luis:default.1330123.1
2016-09-16 09:18:23.816963 7fd5c4f81700 20 get_system_obj_state: rctx=0x7fd5c4f7f710 obj=.rgw:.bucket.meta.luis:default.1330123.1 state=0x7fd638017c28 s->prefetch_data=0
2016-09-16 09:18:23.816967 7fd5c4f81700 10 cache get: name=.rgw+.bucket.meta.luis:default.1330123.1 : hit (requested=22, cached=23)
2016-09-16 09:18:23.816970 7fd5c4f81700 20 get_system_obj_state: s->obj_tag was set empty
2016-09-16 09:18:23.816971 7fd5c4f81700 20 Read xattr: user.rgw.acl
2016-09-16 09:18:23.816972 7fd5c4f81700 20 Read xattr: user.rgw.idtag
2016-09-16 09:18:23.816972 7fd5c4f81700 20 Read xattr: user.rgw.manifest
2016-09-16 09:18:23.816973 7fd5c4f81700 10 cache get: name=.rgw+.bucket.meta.luis:default.1330123.1 : hit (requested=17, cached=23)
2016-09-16 09:18:23.816984 7fd5c4f81700 10 chain_cache_entry: cache_locator=.rgw+luis
2016-09-16 09:18:23.816985 7fd5c4f81700 10 chain_cache_entry: cache_locator=.rgw+.bucket.meta.luis:default.1330123.1
2016-09-16 09:18:23.816994 7fd5c4f81700 15 decode_policy Read AccessControlPolicy<AccessControlPolicy xmlns="http://s3.amazonaws.com/doc/2006-03-01/"><Owner><ID>luis</ID><DisplayName>luis test user</DisplayName></Owner><AccessControlList><Grant><Grantee xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance" xsi:type="CanonicalUser"><ID>luis</ID><DisplayName>luis test user</DisplayName></Grantee><Permission>FULL_CONTROL</Permission></Grant></AccessControlList></AccessControlPolicy>
2016-09-16 09:18:23.816999 7fd5c4f81700 2 req 2:0.000930:s3:PUT /s3cfg_stratus:put_obj:recalculating target
2016-09-16 09:18:23.817001 7fd5c4f81700 2 req 2:0.000933:s3:PUT /s3cfg_stratus:put_obj:reading permissions
2016-09-16 09:18:23.817005 7fd5c4f81700 2 req 2:0.000936:s3:PUT /s3cfg_stratus:put_obj:init op
2016-09-16 09:18:23.817007 7fd5c4f81700 2 req 2:0.000938:s3:PUT /s3cfg_stratus:put_obj:verifying op mask
2016-09-16 09:18:23.817007 7fd5c4f81700 20 required_mask= 2 user.op_mask=7
2016-09-16 09:18:23.817008 7fd5c4f81700 2 req 2:0.000939:s3:PUT /s3cfg_stratus:put_obj:verifying op permissions
2016-09-16 09:18:23.817009 7fd5c4f81700 5 Searching permissions for uid=luis mask=50
2016-09-16 09:18:23.817010 7fd5c4f81700 5 Found permission: 15
2016-09-16 09:18:23.817011 7fd5c4f81700 5 Searching permissions for group=1 mask=50
2016-09-16 09:18:23.817011 7fd5c4f81700 5 Permissions for group not found
2016-09-16 09:18:23.817012 7fd5c4f81700 5 Searching permissions for group=2 mask=50
2016-09-16 09:18:23.817013 7fd5c4f81700 5 Permissions for group not found
2016-09-16 09:18:23.817013 7fd5c4f81700 5 Getting permissions id=luis owner=luis perm=2
2016-09-16 09:18:23.817014 7fd5c4f81700 10 uid=luis requested perm (type)=2, policy perm=2, user_perm_mask=2, acl perm=2
2016-09-16 09:18:23.817016 7fd5c4f81700 2 req 2:0.000945:s3:PUT /s3cfg_stratus:put_obj:verifying op params
2016-09-16 09:18:23.817018 7fd5c4f81700 2 req 2:0.000949:s3:PUT /s3cfg_stratus:put_obj:pre-executing
2016-09-16 09:18:23.817019 7fd5c4f81700 2 req 2:0.000950:s3:PUT /s3cfg_stratus:put_obj:executing
2016-09-16 09:18:23.817103 7fd5c4f81700 10 payload request hash = b18765bc05bf77dd750cd05e57195081222a211b0e3ec4637be54756d71de979
2016-09-16 09:18:23.817126 7fd5c4f81700 10 canonical request = PUT
/s3cfg_stratus
page=s3cfg_stratus¶ms=
content-length:1354
content-type:text/plain
host:luis.s3stratus.inflab.ocado.com
x-amz-content-sha256:b18765bc05bf77dd750cd05e57195081222a211b0e3ec4637be54756d71de979
x-amz-date:20160916T081823Z
x-amz-meta-s3cmd-attrs:uid:1000/gname:luis/uname:luis/gid:1000/mode:33152/mtime:1474013666/atime:1474013678/md5:e9aee935aba54366ec3cf58869e598dc/ctime:1474013666
x-amz-storage-class:STANDARD
content-length;content-type;host;x-amz-content-sha256;x-amz-date;x-amz-meta-s3cmd-attrs;x-amz-storage-class
b18765bc05bf77dd750cd05e57195081222a211b0e3ec4637be54756d71de979
2016-09-16 09:18:23.817129 7fd5c4f81700 10 canonical request hash = 2a90d1d6c42904cfda59965501748ab03a197f63be3ea9f0490cfdacacd572be
2016-09-16 09:18:23.817132 7fd5c4f81700 10 string to sign = AWS4-HMAC-SHA256
20160916T081823Z
20160916/US/s3/aws4_request
2a90d1d6c42904cfda59965501748ab03a197f63be3ea9f0490cfdacacd572be
2016-09-16 09:18:23.817153 7fd5c4f81700 10 date_k = 5de0fe6cbbd1c7f0cbae1b9123e0df1300de69e86cce88bb9b2aab2837dd1fee
2016-09-16 09:18:23.817183 7fd5c4f81700 10 region_k = 8d598fb8a0cd5658cce911790d8f7295c1b80a975cbc7cc20bf8fc0d92701ed8
2016-09-16 09:18:23.817220 7fd5c4f81700 10 service_k = 06f9337b2ddcd0ef62f3c5bb898f1e79653a13db810580873e69bb85516260f1
2016-09-16 09:18:23.817236 7fd5c4f81700 10 signing_k = 3e60b563bb70c72120462681bbaed28e67a63aae268f748980f4c4fa4b5d0a6d
2016-09-16 09:18:23.817251 7fd5c4f81700 10 signature_k = 7221be9c76ae6595b5190f54bd898548cb16fd817a331a7eb6da80e0110078b9
2016-09-16 09:18:23.817253 7fd5c4f81700 10 new signature = 7221be9c76ae6595b5190f54bd898548cb16fd817a331a7eb6da80e0110078b9
2016-09-16 09:18:23.817254 7fd5c4f81700 10 ----------------------------- Verifying signatures
2016-09-16 09:18:23.817255 7fd5c4f81700 10 Signature = 6845cb459d6ec0c4770318f5948ed2c216d97776c13154ab9b041283df74b692
2016-09-16 09:18:23.817255 7fd5c4f81700 10 New Signature = 7221be9c76ae6595b5190f54bd898548cb16fd817a331a7eb6da80e0110078b9
2016-09-16 09:18:23.817256 7fd5c4f81700 10 -----------------------------
2016-09-16 09:18:23.817257 7fd5c4f81700 20 delayed aws4 auth failed
2016-09-16 09:18:23.817264 7fd5c4f81700 2 req 2:0.001195:s3:PUT /s3cfg_stratus:put_obj:completing
2016-09-16 09:18:23.817282 7fd5c4f81700 2 req 2:0.001214:s3:PUT /s3cfg_stratus:put_obj:op status=-2027
2016-09-16 09:18:23.817285 7fd5c4f81700 2 req 2:0.001216:s3:PUT /s3cfg_stratus:put_obj:http status=403
2016-09-16 09:18:23.817288 7fd5c4f81700 1 ====== req done req=0x7fd62c022a10 op status=-2027 http_status=403 ======
2016-09-16 09:18:23.817296 7fd5c4f81700 20 process_request() returned -2027
and this is what I get on "s3cmd c s3cfg_stratus --debug sync . s3://luis/" >C0...17_chars...U
DEBUG: s3cmd version 1.6.1
DEBUG: ConfigParser: Reading file 's3cfg_stratus'
DEBUG: ConfigParser: access_key
DEBUG: ConfigParser: bucket_location->US
DEBUG: ConfigParser: cloudfront_host->cloudfront.amazonaws.com
DEBUG: ConfigParser: default_mime_type->binary/octet-stream
DEBUG: ConfigParser: delete_removed->False
DEBUG: ConfigParser: dry_run->False
DEBUG: ConfigParser: enable_multipart->True
DEBUG: ConfigParser: encoding->ANSI_X3.4-1968
DEBUG: ConfigParser: encrypt->False
DEBUG: ConfigParser: follow_symlinks->False
DEBUG: ConfigParser: force->False
DEBUG: ConfigParser: get_continue->False
DEBUG: ConfigParser: gpg_command->/usr/bin/gpg
DEBUG: ConfigParser: gpg_decrypt->s d --verbose --no-use-agent --batch --yes --passphrase-fd %(passphrase_fd)s -o %(output_file)s %(input_file)s>(gpg_command)s
DEBUG: ConfigParser: gpg_encryptc --verbose --no-use-agent --batch --yes --passphrase-fd s -o %(output_file)s %(input_file)s>...-3_chars...
DEBUG: ConfigParser: gpg_passphrase
DEBUG: ConfigParser: guess_mime_type->True
DEBUG: ConfigParser: host_base->s3stratus.inflab.ocado.com
DEBUG: ConfigParser: host_bucket->(bucket)s.s3stratus.inflab.ocado.com
DEBUG: ConfigParser: human_readable_sizes->False
DEBUG: ConfigParser: invalidate_on_cf->False
DEBUG: ConfigParser: list_md5->False
DEBUG: ConfigParser: log_target_prefix->
DEBUG: ConfigParser: mime_type->
DEBUG: ConfigParser: multipart_chunk_size_mb->15
DEBUG: ConfigParser: preserve_attrs->True
DEBUG: ConfigParser: progress_meter->True
DEBUG: ConfigParser: proxy_host->
DEBUG: ConfigParser: proxy_port->0
DEBUG: ConfigParser: recursive->False
DEBUG: ConfigParser: recv_chunk->4096
DEBUG: ConfigParser: reduced_redundancy->False
DEBUG: ConfigParser: secret_key->7P...37_chars...Z
DEBUG: ConfigParser: send_chunk->4096
DEBUG: ConfigParser: simpledb_host->sdb.amazonaws.com
DEBUG: ConfigParser: skip_existing->False
DEBUG: ConfigParser: socket_timeout->300
DEBUG: ConfigParser: urlencoding_mode->normal
DEBUG: ConfigParser: use_https->False
DEBUG: ConfigParser: verbosity->WARNING
DEBUG: ConfigParser: website_endpoint->http://%(bucket)s.s3-website-%(location)s.amazonaws.com/
DEBUG: ConfigParser: website_error->
DEBUG: ConfigParser: website_index->index.html
DEBUG: Updating Config.Config cache_file ->
DEBUG: Updating Config.Config follow_symlinks -> False
DEBUG: Updating Config.Config verbosity -> 10
DEBUG: Unicodising 'sync' using ANSI_X3.4-1968
DEBUG: Unicodising '.' using ANSI_X3.4-1968
DEBUG: Unicodising 's3://luis/' using ANSI_X3.4-1968
DEBUG: Command: sync
DEBUG: DeUnicodising u'.' using ANSI_X3.4-1968
DEBUG: DeUnicodising u'.' using ANSI_X3.4-1968
INFO: Compiling list of local files...
DEBUG: DeUnicodising u'.' using ANSI_X3.4-1968
DEBUG: DeUnicodising u'.' using ANSI_X3.4-1968
DEBUG: Unicodising 's3cfg_stratus' using ANSI_X3.4-1968
DEBUG: DeUnicodising u'./s3cfg_stratus' using ANSI_X3.4-1968
DEBUG: DeUnicodising u'./s3cfg_stratus' using ANSI_X3.4-1968
DEBUG: DeUnicodising u'./s3cfg_stratus' using ANSI_X3.4-1968
DEBUG: Applying --exclude/--include
DEBUG: CHECK: s3cfg_stratus
DEBUG: PASS: u's3cfg_stratus'
INFO: Running stat() and reading/calculating MD5 values on 1 files, this may take some time...
DEBUG: DeUnicodising u'./s3cfg_stratus' using ANSI_X3.4-1968
DEBUG: doing file I/O to read md5 of s3cfg_stratus
DEBUG: DeUnicodising u'./s3cfg_stratus' using ANSI_X3.4-1968
INFO: Retrieving list of remote files for s3://luis/. ...
DEBUG: String '.' encoded to '.'
DEBUG: CreateRequest: resource[uri]=/
DEBUG: Using signature v4
DEBUG: get_hostname(luis): luis.s3stratus.inflab.ocado.com
DEBUG: canonical_headers = host:luis.s3stratus.inflab.ocado.com
x-amz-content-sha256:e3b0c44298fc1c149afbf4c8996fb92427ae41e4649b934ca495991b7852b855
x-amz-date:20160916T083811Z
DEBUG: Canonical Request:
GET
/
prefix=.
host:luis.s3stratus.inflab.ocado.com
x-amz-content-sha256:e3b0c44298fc1c149afbf4c8996fb92427ae41e4649b934ca495991b7852b855
x-amz-date:20160916T083811Z
host;x-amz-content-sha256;x-amz-date
e3b0c44298fc1c149afbf4c8996fb92427ae41e4649b934ca495991b7852b855
----------------------
DEBUG: signature-v4 headers: {'x-amz-content-sha256': 'e3b0c44298fc1c149afbf4c8996fb92427ae41e4649b934ca495991b7852b855', 'Authorization': 'AWS4-HMAC-SHA256 Credential=C0K66XRJC2NW0O0WN06U/20160916/US/s3/aws4_request,SignedHeaders=host;x-amz-content-sha256;x-amz-date,Signature=6e6d71b78d7d0d00c3d42047f3af5b87077fa903ad1a4580cc8ac0ea164b3c9c', 'x-amz-date': '20160916T083811Z'}
DEBUG: Processing request, please wait...
DEBUG: get_hostname(luis): luis.s3stratus.inflab.ocado.com
DEBUG: ConnMan.get(): creating new connection: http://luis.s3stratus.inflab.ocado.com
DEBUG: non-proxied HTTPConnection(luis.s3stratus.inflab.ocado.com)
DEBUG: format_uri(): /?prefix=.
DEBUG: Sending request method_string='GET', uri='/?prefix=.', headers={'x-amz-content-sha256': 'e3b0c44298fc1c149afbf4c8996fb92427ae41e4649b934ca495991b7852b855', 'Authorization': 'AWS4-HMAC-SHA256 Credential=C0K66XRJC2NW0O0WN06U/20160916/US/s3/aws4_request,SignedHeaders=host;x-amz-content-sha256;x-amz-date,Signature=6e6d71b78d7d0d00c3d42047f3af5b87077fa903ad1a4580cc8ac0ea164b3c9c', 'x-amz-date': '20160916T083811Z'}, body=(0 bytes)
DEBUG: Response: {'status': 200, 'headers': {'transfer-encoding': 'chunked', 'server': 'Apache/2.4.7 (Ubuntu)', 'connection': 'close', 'x-amz-request-id': 'tx000000000000000000001-0057dbaf73-1dd7a3-default', 'date': 'Fri, 16 Sep 2016 08:38:11 GMT', 'content-type': 'application/xml'}, 'reason': 'OK', 'data': '<ListBucketResult xmlns="http://s3.amazonaws.com/doc/2006-03-01/"><Name>luis</Name><Prefix>.</Prefix><Marker></Marker><MaxKeys>1000</MaxKeys><IsTruncated>false</IsTruncated></ListBucketResult>'}
DEBUG: ConnMan.put(): connection put back to pool (http://luis.s3stratus.inflab.ocado.com#1)
DEBUG: Applying --exclude/--include
INFO: Found 1 local files, 0 remote files
INFO: Verifying attributes...
DEBUG: Comparing filelists (direction: local -> remote)
DEBUG: CHECK: s3cfg_stratus
INFO: Summary: 1 local files to upload, 0 files to remote copy, 0 remote files to delete
DEBUG: attr_header: {'x-amz-meta-s3cmd-attrs': 'uid:1000/gname:luis/uname:luis/gid:1000/mode:33152/mtime:1474013666/atime:1474013678/md5:e9aee935aba54366ec3cf58869e598dc/ctime:1474013666'}
DEBUG: DeUnicodising u'./s3cfg_stratus' using ANSI_X3.4-1968
DEBUG: DeUnicodising u'./s3cfg_stratus' using ANSI_X3.4-1968
DEBUG: DeUnicodising u'./s3cfg_stratus' using ANSI_X3.4-1968
DEBUG: String 's3cfg_stratus' encoded to 's3cfg_stratus'
DEBUG: CreateRequest: resource[uri]=/s3cfg_stratus
DEBUG: Using signature v4
DEBUG: get_hostname(luis): luis.s3stratus.inflab.ocado.com
DEBUG: canonical_headers = content-length:1354
content-type:text/plain
host:luis.s3stratus.inflab.ocado.com
x-amz-content-sha256:e3b0c44298fc1c149afbf4c8996fb92427ae41e4649b934ca495991b7852b855
x-amz-date:20160916T083811Z
x-amz-meta-s3cmd-attrs:uid:1000/gname:luis/uname:luis/gid:1000/mode:33152/mtime:1474013666/atime:1474013678/md5:e9aee935aba54366ec3cf58869e598dc/ctime:1474013666
x-amz-storage-class:STANDARD
DEBUG: Canonical Request:
PUT
/s3cfg_stratus
content-length:1354
content-type:text/plain
host:luis.s3stratus.inflab.ocado.com
x-amz-content-sha256:e3b0c44298fc1c149afbf4c8996fb92427ae41e4649b934ca495991b7852b855
x-amz-date:20160916T083811Z
x-amz-meta-s3cmd-attrs:uid:1000/gname:luis/uname:luis/gid:1000/mode:33152/mtime:1474013666/atime:1474013678/md5:e9aee935aba54366ec3cf58869e598dc/ctime:1474013666
x-amz-storage-class:STANDARD
content-length;content-type;host;x-amz-content-sha256;x-amz-date;x-amz-meta-s3cmd-attrs;x-amz-storage-class
e3b0c44298fc1c149afbf4c8996fb92427ae41e4649b934ca495991b7852b855
----------------------
DEBUG: signature-v4 headers: {'x-amz-content-sha256': 'e3b0c44298fc1c149afbf4c8996fb92427ae41e4649b934ca495991b7852b855', 'content-length': '1354', 'x-amz-storage-class': 'STANDARD', 'x-amz-meta-s3cmd-attrs': 'uid:1000/gname:luis/uname:luis/gid:1000/mode:33152/mtime:1474013666/atime:1474013678/md5:e9aee935aba54366ec3cf58869e598dc/ctime:1474013666', 'x-amz-date': '20160916T083811Z', 'content-type': 'text/plain', 'Authorization': 'AWS4-HMAC-SHA256 Credential=C0K66XRJC2NW0O0WN06U/20160916/US/s3/aws4_request,SignedHeaders=content-length;content-type;host;x-amz-content-sha256;x-amz-date;x-amz-meta-s3cmd-attrs;x-amz-storage-class,Signature=7439a11f3d764c99453de9edaeca3b27ec6c37d5594e508c622d91279d8fa3e6'}
DEBUG: Unicodising './s3cfg_stratus' using ANSI_X3.4-1968
upload: './s3cfg_stratus' -> 's3://luis/s3cfg_stratus' [1 of 1]
DEBUG: DeUnicodising u'./s3cfg_stratus' using ANSI_X3.4-1968
DEBUG: Using signature v4
DEBUG: get_hostname(luis): luis.s3stratus.inflab.ocado.com
DEBUG: canonical_headers = content-length:1354
content-type:text/plain
host:luis.s3stratus.inflab.ocado.com
x-amz-content-sha256:b18765bc05bf77dd750cd05e57195081222a211b0e3ec4637be54756d71de979
x-amz-date:20160916T083811Z
x-amz-meta-s3cmd-attrs:uid:1000/gname:luis/uname:luis/gid:1000/mode:33152/mtime:1474013666/atime:1474013678/md5:e9aee935aba54366ec3cf58869e598dc/ctime:1474013666
x-amz-storage-class:STANDARD
DEBUG: Canonical Request:
PUT
/s3cfg_stratus
content-length:1354
content-type:text/plain
host:luis.s3stratus.inflab.ocado.com
x-amz-content-sha256:b18765bc05bf77dd750cd05e57195081222a211b0e3ec4637be54756d71de979
x-amz-date:20160916T083811Z
x-amz-meta-s3cmd-attrs:uid:1000/gname:luis/uname:luis/gid:1000/mode:33152/mtime:1474013666/atime:1474013678/md5:e9aee935aba54366ec3cf58869e598dc/ctime:1474013666
x-amz-storage-class:STANDARD
content-length;content-type;host;x-amz-content-sha256;x-amz-date;x-amz-meta-s3cmd-attrs;x-amz-storage-class
b18765bc05bf77dd750cd05e57195081222a211b0e3ec4637be54756d71de979
----------------------
DEBUG: signature-v4 headers: {'x-amz-content-sha256': 'b18765bc05bf77dd750cd05e57195081222a211b0e3ec4637be54756d71de979', 'content-length': '1354', 'x-amz-storage-class': 'STANDARD', 'x-amz-meta-s3cmd-attrs': 'uid:1000/gname:luis/uname:luis/gid:1000/mode:33152/mtime:1474013666/atime:1474013678/md5:e9aee935aba54366ec3cf58869e598dc/ctime:1474013666', 'x-amz-date': '20160916T083811Z', 'content-type': 'text/plain', 'Authorization': 'AWS4-HMAC-SHA256 Credential=C0K66XRJC2NW0O0WN06U/20160916/US/s3/aws4_request,SignedHeaders=content-length;content-type;host;x-amz-content-sha256;x-amz-date;x-amz-meta-s3cmd-attrs;x-amz-storage-class,Signature=c6aeec7ec539a872e0a604f69cb456ec6158aef2a0e5ef1f6f562820190efab6'}
DEBUG: get_hostname(luis): luis.s3stratus.inflab.ocado.com
DEBUG: ConnMan.get(): re-using connection: http://luis.s3stratus.inflab.ocado.com#1
DEBUG: format_uri(): /s3cfg_stratus
1354 of 1354 100% in 0s 461.36 kB/sDEBUG: ConnMan.put(): connection put back to pool (http://luis.s3stratus.inflab.ocado.com#2)
DEBUG: Response: {'status': 403, 'headers': {'content-length': '227', 'accept-ranges': 'bytes', 'server': 'Apache/2.4.7 (Ubuntu)', 'connection': 'close', 'x-amz-request-id': 'tx000000000000000000002-0057dbaf73-1dd7a3-default', 'date': 'Fri, 16 Sep 2016 08:38:11 GMT', 'content-type': 'application/xml'}, 'reason': 'Forbidden', 'data': '<Error><Code>SignatureDoesNotMatch</Code><BucketName>luis</BucketName><RequestId>tx000000000000000000002-0057dbaf73-1dd7a3-default</RequestId><HostId>1dd7a3-default-default</HostId></Error>', 'size': 1354L}
1354 of 1354 100% in 0s 188.12 kB/s done
DEBUG: S3Error: 403 (Forbidden)
DEBUG: HttpHeader: content-length: 227
DEBUG: HttpHeader: accept-ranges: bytes
DEBUG: HttpHeader: server: Apache/2.4.7 (Ubuntu)
DEBUG: HttpHeader: connection: close
DEBUG: HttpHeader: x-amz-request-id: tx000000000000000000002-0057dbaf73-1dd7a3-default
DEBUG: HttpHeader: date: Fri, 16 Sep 2016 08:38:11 GMT
DEBUG: HttpHeader: content-type: application/xml
DEBUG: ErrorXML: Code: 'SignatureDoesNotMatch'
DEBUG: ErrorXML: BucketName: 'luis'
DEBUG: ErrorXML: RequestId: 'tx000000000000000000002-0057dbaf73-1dd7a3-default'
DEBUG: ErrorXML: HostId: '1dd7a3-default-default'
ERROR: S3 error: 403 (SignatureDoesNotMatch)
I can also send a tcpdump of the connection, but it doesn't say much...
Updated by Dennis Kramer over 7 years ago
Hi, is the fix (https://github.com/ceph/ceph/pull/10919) going to be backported for 10.2.4 point release?
Updated by Loïc Dachary over 7 years ago
- Status changed from Resolved to Pending Backport
- Backport set to jewel
Updated by Loïc Dachary over 7 years ago
- Copied to Backport #18349: jewel: AWS S3 Version 4 signatures fail sometimes. added
Updated by Nathan Cutler about 7 years ago
- Status changed from Pending Backport to Resolved
Updated by Ben Hines about 7 years ago
This basically prevents RadosGW use with Kraken with modern clients by default. Could it be backported to K?
Updated by Nathan Cutler about 7 years ago
- Project changed from Ceph to rgw
- Category deleted (
22)
Updated by Nathan Cutler about 7 years ago
- Related to Bug #19008: rgw: adding bucket lifecycle does not work with V4 signature added
Updated by Nathan Cutler about 7 years ago
As far as I can tell the SHA1 of the fix is 20e5ff023ebad89c386a520d07613547d4836399 and it is included in the kraken (v11.2.0) release.
Updated by Ben Hines about 7 years ago
Thanks -- i'm still seeing general -2201 failures with AWSv4 auth on Kraken 11.2.0. Perhaps i will file a new issue, then.
Updated by Marcus Watts almost 7 years ago
I just fixed another problem with chunked transfers and AWSv4 signatures - see http://tracker.ceph.com/issues/20447 . The problem would most likely only manifest with "large" files in the wild, but I have sample code there that can reliably reproduce the problem with small files.