On 11/21/2016 04:44 PM, Yehuda Sadeh-Weinraub wrote:
On Mon, Nov 21, 2016 at 2:42 PM, Graham Allan <gta@xxxxxxx> wrote:
Following up to this (same problem, looking at it with Jeff)...
There was definite confusion with the zone/zonegroup/realm/period changes
during the hammer->jewel upgrade. It's possible that our placement settings
were misplaced at this time.
However what I find puzzling is that different buckets from the same pool
seem affected - if this were placement related, I'd rather expect all
buckets from one pool to be affected, those in another not. Am I
interpreting this wrongly?
For example here is one bucket which remains accessible:
# radosgw-admin metadata get bucket.instance:gta:default.691974.1
{
"key": "bucket.instance:gta:default.691974.1",
"ver": {
"tag": "_3Z9nfFjZn97aV2YJ4nFhVuk",
"ver": 85
},
"mtime": "2016-11-11 16:48:02.950760Z",
"data": {
"bucket_info": {
"bucket": {
"name": "gta",
"pool": ".rgw.buckets.ec42",
"data_extra_pool": ".rgw.buckets.extra",
"index_pool": ".rgw.buckets.index",
"marker": "default.691974.1",
"bucket_id": "default.691974.1",
"tenant": ""
},
"creation_time": "2015-11-13 20:05:26.000000Z",
"owner": "gta",
"flags": 0,
"zonegroup": "default",
"placement_rule": "ec42-placement",
"has_instance_obj": "true",
"quota": {
"enabled": false,
"max_size_kb": -1,
"max_objects": -1
},
"num_shards": 32,
"bi_shard_hash_type": 0,
"requester_pays": "false",
"has_website": "false",
"swift_versioning": "false",
"swift_ver_location": ""
},
"attrs": [
{
"key": "user.rgw.acl",
"val":
"AgJ\/AAAAAgIXAAAAAwAAAGd0YQwAAABHcmFoYW0gQWxsYW4DA1wAAAABAQAAAAMAAABndGEPAAAAAQAAAAMAAABndGEDAzcAAAACAgQAAAAAAAAAAwAAAGd0YQAAAAAAAAAAAgIEAAAADwAAAAwAAABHcmFoYW0gQWxsYW4AAAAAAAAAAA=="
},
{
"key": "user.rgw.idtag",
"val": ""
},
{
"key": "user.rgw.manifest",
"val": ""
}
]
}
}
while here is another, located in the same pool, which is not accessible:
# radosgw-admin metadata get bucket.instance:tcga:default.712449.19
{
"key": "bucket.instance:tcga:default.712449.19",
"ver": {
"tag": "_vm0Og31XbhhtmnuQVZ6cYJP",
"ver": 2010
},
"mtime": "2016-11-19 03:49:03.406938Z",
"data": {
"bucket_info": {
"bucket": {
"name": "tcga",
"pool": ".rgw.buckets.ec42",
"data_extra_pool": ".rgw.buckets.extra",
"index_pool": ".rgw.buckets.index",
"marker": "default.712449.19",
"bucket_id": "default.712449.19",
"tenant": ""
},
"creation_time": "2016-01-21 20:51:21.000000Z",
"owner": "jmcdonal",
"flags": 0,
"zonegroup": "default",
"placement_rule": "ec42-placement",
"has_instance_obj": "true",
"quota": {
"enabled": false,
"max_size_kb": -1,
"max_objects": -1
},
"num_shards": 0,
"bi_shard_hash_type": 0,
"requester_pays": "false",
"has_website": "false",
"swift_versioning": "false",
"swift_ver_location": ""
},
"attrs": [
{
"key": "user.rgw.acl",
"val":
"AgKbAAAAAgIgAAAACAAAAGptY2RvbmFsEAAAAEplZmZyZXkgTWNEb25hbGQDA28AAAABAQAAAAgAAABqbWNkb25hbA8AAAABAAAACAAAAGptY2RvbmFsAwNAAAAAAgIEAAAAAAAAAAgAAABqbWNkb25hbAAAAAAAAAAAAgIEAAAADwAAABAAAABKZWZmcmV5IE1jRG9uYWxkAAAAAAAAAAA="
},
{
"key": "user.rgw.idtag",
"val": ""
},
{
"key": "user.rgw.manifest",
"val": ""
}
]
}
}
if I do "ls --pool .rgw.buckets.ec42|grep default.712449.19" I can see
objects with the above bucket ID, and fetch them, so I know the data is
there...
Does this seem like a placement_pool issue, or maybe some other unrelated
issue?
Could be another semi-related issue. Can you provide output of the
commands that fail with 'debug rgw = 20' and 'debug ms = 1'?
Thanks,
Yehuda
I captured some radosgw log output when trying to access the failing
bucket above (bucket.instance:tcga:default.712449.19); the output was on
the long side to include inline so I put it online here as well as
attaching:
http://pastebin.com/F5HJ9EeQ
Also did the command "radosgw-admin bucket stats --bucket=tcga" which
also errors but produces even more output - won't attach unless you
think it would be useful.
In both cases it seems related to a directory lookup failure, eg:
2016-11-21 16:48:43.489328 7faeea8f1900 1 -- 10.32.16.93:0/3999194905 --> 10.31.0.70:6851/1771318 -- osd_op(client.2588139.0:160 100.4d86b68f .dir.default.712449.19 [call rgw.bucket_list] snapc 0=[] ack+read+known_if_redirected e455622) v7 -- ?+0 0x7faeeb5acfa0 con 0x7faeeb54baa0
2016-11-21 16:48:43.490411 7fae547ce700 1 -- 10.32.16.93:0/3999194905 <== osd.114 10.31.0.70:6851/1771318 5 ==== osd_op_reply(160 .dir.default.712449.19 [call] v0'0 uv0 ack = -2 ((2) No such file or directory)) v7 ==== 142+0+0 (2988442841 0 0) 0x7fadfc000c20 con 0x7faeeb54baa0
error getting bucket stats ret=-2
Would that be related to these objects in the index pool?
# rados ls --pool .rgw.buckets.index |grep default.712449.19
.dir.default.712449.19.25
.dir.default.712449.19.4
.dir.default.712449.19.10
.dir.default.712449.19.15
.dir.default.712449.19.28
.dir.default.712449.19.8
.dir.default.712449.19.26
.dir.default.712449.19.22
.dir.default.712449.19.11
.dir.default.712449.19.6
.dir.default.712449.19.20
.dir.default.712449.19.7
.dir.default.712449.19.14
.dir.default.712449.19.2
.dir.default.712449.19.21
.dir.default.712449.19.30
.dir.default.712449.19.12
.dir.default.712449.19.27
.dir.default.712449.19.0
.dir.default.712449.19.1
.dir.default.712449.19.31
.dir.default.712449.19.29
.dir.default.712449.19.13
.dir.default.712449.19.16
.dir.default.712449.19.24
.dir.default.712449.19.18
.dir.default.712449.19.19
.dir.default.712449.19.23
.dir.default.712449.19.9
.dir.default.712449.19.5
.dir.default.712449.19.17
.dir.default.712449.19.3
Thanks!
Graham
--
Graham Allan
Minnesota Supercomputing Institute - gta@xxxxxxx
2016-11-21 16:51:12.655322 7f2461feb700 20 RGWEnv::set(): HTTP_HOST: tcga.s3.msi.umn.edu
2016-11-21 16:51:12.655333 7f2461feb700 20 RGWEnv::set(): HTTP_ACCEPT_ENCODING: identity
2016-11-21 16:51:12.655336 7f2461feb700 20 RGWEnv::set(): HTTP_X_AMZ_CONTENT_SHA256: e3b0c44298fc1c149afbf4c8996fb92427ae41e4649b934ca495991b7852b855
2016-11-21 16:51:12.655340 7f2461feb700 20 RGWEnv::set(): HTTP_AUTHORIZATION: AWS4-HMAC-SHA256 Credential=YKG1LLQ9B6JJA087KAX9/20161121/US/s3/aws4_request,SignedHeaders=host;x-amz-content-sha256;x-amz-date,Signature=d24ef59e1205164d6690e821191e71fc044987f8cbb20b062f1da10636a5c5e5
2016-11-21 16:51:12.655344 7f2461feb700 20 RGWEnv::set(): HTTP_X_AMZ_DATE: 20161121T225112Z
2016-11-21 16:51:12.655346 7f2461feb700 20 RGWEnv::set(): REQUEST_METHOD: GET
2016-11-21 16:51:12.655347 7f2461feb700 20 RGWEnv::set(): REQUEST_URI: /
2016-11-21 16:51:12.655349 7f2461feb700 20 RGWEnv::set(): QUERY_STRING: delimiter=/
2016-11-21 16:51:12.655351 7f2461feb700 20 RGWEnv::set(): REMOTE_USER:
2016-11-21 16:51:12.655352 7f2461feb700 20 RGWEnv::set(): SCRIPT_URI: /
2016-11-21 16:51:12.655355 7f2461feb700 20 RGWEnv::set(): SERVER_PORT: 0
2016-11-21 16:51:12.655357 7f2461feb700 20 RGWEnv::set(): SERVER_PORT_SECURE: 443
2016-11-21 16:51:12.655358 7f2461feb700 20 HTTP_ACCEPT_ENCODING=identity
2016-11-21 16:51:12.655359 7f2461feb700 20 HTTP_AUTHORIZATION=AWS4-HMAC-SHA256 Credential=YKG1LLQ9B6JJA087KAX9/20161121/US/s3/aws4_request,SignedHeaders=host;x-amz-content-sha256;x-amz-date,Signature=d24ef59e1205164d6690e821191e71fc044987f8cbb20b062f1da10636a5c5e5
2016-11-21 16:51:12.655361 7f2461feb700 20 HTTP_HOST=tcga.s3.msi.umn.edu
2016-11-21 16:51:12.655362 7f2461feb700 20 HTTP_X_AMZ_CONTENT_SHA256=e3b0c44298fc1c149afbf4c8996fb92427ae41e4649b934ca495991b7852b855
2016-11-21 16:51:12.655363 7f2461feb700 20 HTTP_X_AMZ_DATE=20161121T225112Z
2016-11-21 16:51:12.655364 7f2461feb700 20 QUERY_STRING=delimiter=/
2016-11-21 16:51:12.655364 7f2461feb700 20 REMOTE_USER=
2016-11-21 16:51:12.655365 7f2461feb700 20 REQUEST_METHOD=GET
2016-11-21 16:51:12.655366 7f2461feb700 20 REQUEST_URI=/
2016-11-21 16:51:12.655367 7f2461feb700 20 SCRIPT_URI=/
2016-11-21 16:51:12.655367 7f2461feb700 20 SERVER_PORT=0
2016-11-21 16:51:12.655368 7f2461feb700 20 SERVER_PORT_SECURE=443
2016-11-21 16:51:12.655370 7f2461feb700 1 ====== starting new request req=0x7f2461fe57d0 =====
2016-11-21 16:51:12.655387 7f2461feb700 2 req 36:0.000017::GET /::initializing for trans_id = tx000000000000000000024-0058337a60-277e03-default
2016-11-21 16:51:12.655395 7f2461feb700 10 rgw api priority: s3=5 s3website=4
2016-11-21 16:51:12.655397 7f2461feb700 10 host=tcga.s3.msi.umn.edu
2016-11-21 16:51:12.655399 7f2461feb700 20 subdomain=tcga domain=s3.msi.umn.edu in_hosted_domain=1 in_hosted_domain_s3website=0
2016-11-21 16:51:12.655402 7f2461feb700 20 final domain/bucket subdomain=tcga domain=s3.msi.umn.edu in_hosted_domain=1 in_hosted_domain_s3website=0 s->info.domain=s3.msi.umn.edu s->info.request_uri=/tcga/
2016-11-21 16:51:12.655410 7f2461feb700 10 meta>> HTTP_X_AMZ_CONTENT_SHA256
2016-11-21 16:51:12.655414 7f2461feb700 10 meta>> HTTP_X_AMZ_DATE
2016-11-21 16:51:12.655419 7f2461feb700 10 x>> x-amz-content-sha256:e3b0c44298fc1c149afbf4c8996fb92427ae41e4649b934ca495991b7852b855
2016-11-21 16:51:12.655421 7f2461feb700 10 x>> x-amz-date:20161121T225112Z
2016-11-21 16:51:12.655437 7f2461feb700 20 get_handler handler=25RGWHandler_REST_Bucket_S3
2016-11-21 16:51:12.655441 7f2461feb700 10 handler=25RGWHandler_REST_Bucket_S3
2016-11-21 16:51:12.655443 7f2461feb700 2 req 36:0.000074:s3:GET /::getting op 0
2016-11-21 16:51:12.655457 7f2461feb700 10 op=25RGWListBucket_ObjStore_S3
2016-11-21 16:51:12.655459 7f2461feb700 2 req 36:0.000089:s3:GET /:list_bucket:authorizing
2016-11-21 16:51:12.655490 7f2461feb700 10 v4 signature format = d24ef59e1205164d6690e821191e71fc044987f8cbb20b062f1da10636a5c5e5
2016-11-21 16:51:12.655497 7f2461feb700 10 v4 credential format = YKG1LLQ9B6JJA087KAX9/20161121/US/s3/aws4_request
2016-11-21 16:51:12.655508 7f2461feb700 10 access key id = YKG1LLQ9B6JJA087KAX9
2016-11-21 16:51:12.655510 7f2461feb700 10 credential scope = 20161121/US/s3/aws4_request
2016-11-21 16:51:12.655523 7f2461feb700 20 get_system_obj_state: rctx=0x7f2461fe44c0 obj=.users:YKG1LLQ9B6JJA087KAX9 state=0x7f265800b6c8 s->prefetch_data=0
2016-11-21 16:51:12.655530 7f2461feb700 10 cache get: name=.users+YKG1LLQ9B6JJA087KAX9 : miss
2016-11-21 16:51:12.655627 7f2461feb700 1 -- 128.101.189.204:0/2500521955 --> 10.31.0.66:6844/567068 -- osd_op(client.2588178.0:25 89.26353831 YKG1LLQ9B6JJA087KAX9 [getxattrs,stat] snapc 0=[] ack+read+known_if_redirected e455622) v7 -- ?+0 0x7f265800f310 con 0x7f265800def0
2016-11-21 16:51:12.658431 7f24324f7700 1 -- 128.101.189.204:0/2500521955 <== osd.250 10.31.0.66:6844/567068 1 ==== osd_op_reply(25 YKG1LLQ9B6JJA087KAX9 [getxattrs,stat] v0'0 uv5 ondisk = 0) v7 ==== 182+0+20 (1191192971 0 1018015602) 0x7f27d5feb3c0 con 0x7f265800def0
2016-11-21 16:51:12.658578 7f2461feb700 10 cache put: name=.users+YKG1LLQ9B6JJA087KAX9 info.flags=6
2016-11-21 16:51:12.658596 7f2461feb700 10 adding .users+YKG1LLQ9B6JJA087KAX9 to cache LRU end
2016-11-21 16:51:12.658602 7f2461feb700 20 get_system_obj_state: s->obj_tag was set empty
2016-11-21 16:51:12.658607 7f2461feb700 10 cache get: name=.users+YKG1LLQ9B6JJA087KAX9 : type miss (requested=1, cached=6)
2016-11-21 16:51:12.658612 7f2461feb700 20 get_system_obj_state: rctx=0x7f2461fe44c0 obj=.users:YKG1LLQ9B6JJA087KAX9 state=0x7f265800b6c8 s->prefetch_data=0
2016-11-21 16:51:12.658615 7f2461feb700 20 rados->read ofs=0 len=524288
2016-11-21 16:51:12.658651 7f2461feb700 1 -- 128.101.189.204:0/2500521955 --> 10.31.0.66:6844/567068 -- osd_op(client.2588178.0:26 89.26353831 YKG1LLQ9B6JJA087KAX9 [read 0~524288] snapc 0=[] ack+read+known_if_redirected e455622) v7 -- ?+0 0x7f265800fea0 con 0x7f265800def0
2016-11-21 16:51:12.659602 7f24324f7700 1 -- 128.101.189.204:0/2500521955 <== osd.250 10.31.0.66:6844/567068 2 ==== osd_op_reply(26 YKG1LLQ9B6JJA087KAX9 [read 0~12] v0'0 uv5 ondisk = 0) v7 ==== 140+0+12 (690124652 0 491664042) 0x7f27d5feb3c0 con 0x7f265800def0
2016-11-21 16:51:12.659735 7f2461feb700 20 rados->read r=0 bl.length=12
2016-11-21 16:51:12.659761 7f2461feb700 10 cache put: name=.users+YKG1LLQ9B6JJA087KAX9 info.flags=1
2016-11-21 16:51:12.659768 7f2461feb700 10 moving .users+YKG1LLQ9B6JJA087KAX9 to cache LRU end
2016-11-21 16:51:12.659784 7f2461feb700 20 get_system_obj_state: rctx=0x7f2461fe3fe0 obj=.users.uid:jmcdonal state=0x7f26580113b8 s->prefetch_data=0
2016-11-21 16:51:12.659793 7f2461feb700 10 cache get: name=.users.uid+jmcdonal : miss
2016-11-21 16:51:12.659905 7f2461feb700 1 -- 128.101.189.204:0/2500521955 --> 10.31.0.67:6839/490828 -- osd_op(client.2588178.0:27 88.fe084780 jmcdonal [call version.read,getxattrs,stat] snapc 0=[] ack+read+known_if_redirected e455622) v7 -- ?+0 0x7f2658015bd0 con 0x7f26580128c0
2016-11-21 16:51:12.662848 7f24322f5700 1 -- 128.101.189.204:0/2500521955 <== osd.292 10.31.0.67:6839/490828 1 ==== osd_op_reply(27 jmcdonal [call,getxattrs,stat] v0'0 uv351764 ondisk = 0) v7 ==== 212+0+139 (672327856 0 2928617799) 0x7f24e0003400 con 0x7f26580128c0
2016-11-21 16:51:12.662983 7f2461feb700 10 cache put: name=.users.uid+jmcdonal info.flags=22
2016-11-21 16:51:12.663000 7f2461feb700 10 adding .users.uid+jmcdonal to cache LRU end
2016-11-21 16:51:12.663006 7f2461feb700 20 get_system_obj_state: s->obj_tag was set empty
2016-11-21 16:51:12.663012 7f2461feb700 10 cache get: name=.users.uid+jmcdonal : type miss (requested=17, cached=22)
2016-11-21 16:51:12.663017 7f2461feb700 20 get_system_obj_state: rctx=0x7f2461fe3fe0 obj=.users.uid:jmcdonal state=0x7f26580113b8 s->prefetch_data=0
2016-11-21 16:51:12.663043 7f2461feb700 20 rados->read ofs=0 len=524288
2016-11-21 16:51:12.663081 7f2461feb700 1 -- 128.101.189.204:0/2500521955 --> 10.31.0.67:6839/490828 -- osd_op(client.2588178.0:28 88.fe084780 jmcdonal [call version.check_conds,call version.read,read 0~524288] snapc 0=[] ack+read+known_if_redirected e455622) v7 -- ?+0 0x7f2658018920 con 0x7f26580128c0
2016-11-21 16:51:12.663942 7f24322f5700 1 -- 128.101.189.204:0/2500521955 <== osd.292 10.31.0.67:6839/490828 2 ==== osd_op_reply(28 jmcdonal [call,call,read 0~354] v0'0 uv351764 ondisk = 0) v7 ==== 212+0+402 (3054689730 0 2157744092) 0x7f24e0003400 con 0x7f26580128c0
2016-11-21 16:51:12.664090 7f2461feb700 20 rados->read r=0 bl.length=354
2016-11-21 16:51:12.664111 7f2461feb700 10 cache put: name=.users.uid+jmcdonal info.flags=17
2016-11-21 16:51:12.664116 7f2461feb700 10 moving .users.uid+jmcdonal to cache LRU end
2016-11-21 16:51:12.664137 7f2461feb700 10 chain_cache_entry: cache_locator=.users.uid+jmcdonal
2016-11-21 16:51:12.664199 7f2461feb700 10 canonical headers format = host:tcga.s3.msi.umn.edu
x-amz-content-sha256:e3b0c44298fc1c149afbf4c8996fb92427ae41e4649b934ca495991b7852b855
x-amz-date:20161121T225112Z
2016-11-21 16:51:12.664250 7f2461feb700 10 payload request hash = e3b0c44298fc1c149afbf4c8996fb92427ae41e4649b934ca495991b7852b855
2016-11-21 16:51:12.664279 7f2461feb700 10 canonical request = GET
/
delimiter=%2F
host:tcga.s3.msi.umn.edu
x-amz-content-sha256:e3b0c44298fc1c149afbf4c8996fb92427ae41e4649b934ca495991b7852b855
x-amz-date:20161121T225112Z
host;x-amz-content-sha256;x-amz-date
e3b0c44298fc1c149afbf4c8996fb92427ae41e4649b934ca495991b7852b855
2016-11-21 16:51:12.664282 7f2461feb700 10 canonical request hash = f92f5af68b19a3812a71bc9da96bb82207009c04b58ed39d23b4fb21bd770b88
2016-11-21 16:51:12.664286 7f2461feb700 10 string to sign = AWS4-HMAC-SHA256
20161121T225112Z
20161121/US/s3/aws4_request
f92f5af68b19a3812a71bc9da96bb82207009c04b58ed39d23b4fb21bd770b88
2016-11-21 16:51:12.664335 7f2461feb700 10 date_k = fec6e25d2279b1afaecd55224529b94ceb18badfd62b412415f723d9d929a3e6
2016-11-21 16:51:12.664373 7f2461feb700 10 region_k = c0e75ad008c0683f85ecf84254418a78a5d5e5648c54ae9c27c03de892d3c313
2016-11-21 16:51:12.664410 7f2461feb700 10 service_k = 342fe872df30ad9d728447e507866ad668cf834f1a0b95ff730e2232b8f6cd5e
2016-11-21 16:51:12.664445 7f2461feb700 10 signing_k = 4ba7b3b608ece42ecfd00895c0ccb866a9f1edbbe89100b6bb065ea04f4e4524
2016-11-21 16:51:12.664480 7f2461feb700 10 signature_k = d24ef59e1205164d6690e821191e71fc044987f8cbb20b062f1da10636a5c5e5
2016-11-21 16:51:12.664485 7f2461feb700 10 new signature = d24ef59e1205164d6690e821191e71fc044987f8cbb20b062f1da10636a5c5e5
2016-11-21 16:51:12.664486 7f2461feb700 10 ----------------------------- Verifying signatures
2016-11-21 16:51:12.664487 7f2461feb700 10 Signature = d24ef59e1205164d6690e821191e71fc044987f8cbb20b062f1da10636a5c5e5
2016-11-21 16:51:12.664488 7f2461feb700 10 New Signature = d24ef59e1205164d6690e821191e71fc044987f8cbb20b062f1da10636a5c5e5
2016-11-21 16:51:12.664489 7f2461feb700 10 -----------------------------
2016-11-21 16:51:12.664491 7f2461feb700 10 v4 auth ok
2016-11-21 16:51:12.664495 7f2461feb700 2 req 36:0.009125:s3:GET /:list_bucket:normalizing buckets and tenants
2016-11-21 16:51:12.664501 7f2461feb700 10 s->object=<NULL> s->bucket=tcga
2016-11-21 16:51:12.664504 7f2461feb700 2 req 36:0.009134:s3:GET /:list_bucket:init permissions
2016-11-21 16:51:12.664517 7f2461feb700 20 get_system_obj_state: rctx=0x7f2461fe56e0 obj=.rgw:tcga state=0x7f26580177e8 s->prefetch_data=0
2016-11-21 16:51:12.664524 7f2461feb700 10 cache get: name=.rgw+tcga : miss
2016-11-21 16:51:12.664635 7f2461feb700 1 -- 128.101.189.204:0/2500521955 --> 10.31.0.68:6827/2922333 -- osd_op(client.2588178.0:29 86.88dafd3c tcga [call version.read,getxattrs,stat] snapc 0=[] ack+read+known_if_redirected e455622) v7 -- ?+0 0x7f265801c420 con 0x7f2658019110
2016-11-21 16:51:12.667763 7f24320f3700 1 -- 128.101.189.204:0/2500521955 <== osd.30 10.31.0.68:6827/2922333 1 ==== osd_op_reply(29 tcga [call,getxattrs,stat] v0'0 uv35822 ondisk = 0) v7 ==== 208+0+139 (2735528706 0 1607692680) 0x7f2470001430 con 0x7f2658019110
2016-11-21 16:51:12.667818 7f2461feb700 10 cache put: name=.rgw+tcga info.flags=22
2016-11-21 16:51:12.667829 7f2461feb700 10 adding .rgw+tcga to cache LRU end
2016-11-21 16:51:12.667833 7f2461feb700 20 get_system_obj_state: s->obj_tag was set empty
2016-11-21 16:51:12.667835 7f2461feb700 20 Read xattr: user.rgw.idtag
2016-11-21 16:51:12.667837 7f2461feb700 20 Read xattr: user.rgw.manifest
2016-11-21 16:51:12.667841 7f2461feb700 10 cache get: name=.rgw+tcga : type miss (requested=17, cached=22)
2016-11-21 16:51:12.667845 7f2461feb700 20 get_system_obj_state: rctx=0x7f2461fe56e0 obj=.rgw:tcga state=0x7f26580177e8 s->prefetch_data=0
2016-11-21 16:51:12.667869 7f2461feb700 20 rados->read ofs=0 len=524288
2016-11-21 16:51:12.667907 7f2461feb700 1 -- 128.101.189.204:0/2500521955 --> 10.31.0.68:6827/2922333 -- osd_op(client.2588178.0:30 86.88dafd3c tcga [call version.check_conds,call version.read,read 0~524288] snapc 0=[] ack+read+known_if_redirected e455622) v7 -- ?+0 0x7f265801f510 con 0x7f2658019110
2016-11-21 16:51:12.668991 7f24320f3700 1 -- 128.101.189.204:0/2500521955 <== osd.30 10.31.0.68:6827/2922333 2 ==== osd_op_reply(30 tcga [call,call,read 0~148] v0'0 uv35822 ondisk = 0) v7 ==== 208+0+196 (3616551332 0 2053818029) 0x7f2470001560 con 0x7f2658019110
2016-11-21 16:51:12.669074 7f2461feb700 20 rados->read r=0 bl.length=148
2016-11-21 16:51:12.669088 7f2461feb700 10 cache put: name=.rgw+tcga info.flags=17
2016-11-21 16:51:12.669092 7f2461feb700 10 moving .rgw+tcga to cache LRU end
2016-11-21 16:51:12.669104 7f2461feb700 20 rgw_get_bucket_info: bucket instance: tcga(@{i=.rgw.buckets.index,e=.rgw.buckets.extra}.rgw.buckets.ec42[default.712449.19])
2016-11-21 16:51:12.669111 7f2461feb700 20 reading from .rgw:.bucket.meta.tcga:default.712449.19
2016-11-21 16:51:12.669120 7f2461feb700 20 get_system_obj_state: rctx=0x7f2461fe56e0 obj=.rgw:.bucket.meta.tcga:default.712449.19 state=0x7f2658018748 s->prefetch_data=0
2016-11-21 16:51:12.669198 7f2461feb700 10 cache get: name=.rgw+.bucket.meta.tcga:default.712449.19 : miss
2016-11-21 16:51:12.669313 7f2461feb700 1 -- 128.101.189.204:0/2500521955 --> 10.31.0.66:6833/563585 -- osd_op(client.2588178.0:31 86.8c5e313b .bucket.meta.tcga:default.712449.19 [call version.read,getxattrs,stat] snapc 0=[] ack+read+known_if_redirected e455622) v7 -- ?+0 0x7f2658021ea0 con 0x7f265801eb60
2016-11-21 16:51:12.672128 7f2431ef1700 1 -- 128.101.189.204:0/2500521955 <== osd.245 10.31.0.66:6833/563585 1 ==== osd_op_reply(31 .bucket.meta.tcga:default.712449.19 [call,getxattrs,stat] v0'0 uv58800 ondisk = 0) v7 ==== 239+0+320 (3938913966 0 3388770584) 0x7f24740028e0 con 0x7f265801eb60
2016-11-21 16:51:12.672253 7f2461feb700 10 cache put: name=.rgw+.bucket.meta.tcga:default.712449.19 info.flags=22
2016-11-21 16:51:12.672265 7f2461feb700 10 adding .rgw+.bucket.meta.tcga:default.712449.19 to cache LRU end
2016-11-21 16:51:12.672268 7f2461feb700 10 updating xattr: name=user.rgw.acl bl.length()=161
2016-11-21 16:51:12.672274 7f2461feb700 20 get_system_obj_state: s->obj_tag was set empty
2016-11-21 16:51:12.672277 7f2461feb700 20 Read xattr: user.rgw.acl
2016-11-21 16:51:12.672278 7f2461feb700 20 Read xattr: user.rgw.idtag
2016-11-21 16:51:12.672279 7f2461feb700 20 Read xattr: user.rgw.manifest
2016-11-21 16:51:12.672284 7f2461feb700 10 cache get: name=.rgw+.bucket.meta.tcga:default.712449.19 : type miss (requested=17, cached=22)
2016-11-21 16:51:12.672289 7f2461feb700 20 get_system_obj_state: rctx=0x7f2461fe56e0 obj=.rgw:.bucket.meta.tcga:default.712449.19 state=0x7f2658018748 s->prefetch_data=0
2016-11-21 16:51:12.672318 7f2461feb700 20 rados->read ofs=0 len=524288
2016-11-21 16:51:12.672361 7f2461feb700 1 -- 128.101.189.204:0/2500521955 --> 10.31.0.66:6833/563585 -- osd_op(client.2588178.0:32 86.8c5e313b .bucket.meta.tcga:default.712449.19 [call version.check_conds,call version.read,read 0~524288] snapc 0=[] ack+read+known_if_redirected e455622) v7 -- ?+0 0x7f2658025000 con 0x7f265801eb60
2016-11-21 16:51:12.673507 7f2431ef1700 1 -- 128.101.189.204:0/2500521955 <== osd.245 10.31.0.66:6833/563585 2 ==== osd_op_reply(32 .bucket.meta.tcga:default.712449.19 [call,call,read 0~232] v0'0 uv58800 ondisk = 0) v7 ==== 239+0+280 (1793318487 0 2603544759) 0x7f2474002be0 con 0x7f265801eb60
2016-11-21 16:51:12.673622 7f2461feb700 20 rados->read r=0 bl.length=232
2016-11-21 16:51:12.673637 7f2461feb700 10 cache put: name=.rgw+.bucket.meta.tcga:default.712449.19 info.flags=17
2016-11-21 16:51:12.673641 7f2461feb700 10 moving .rgw+.bucket.meta.tcga:default.712449.19 to cache LRU end
2016-11-21 16:51:12.673660 7f2461feb700 10 chain_cache_entry: cache_locator=.rgw+tcga
2016-11-21 16:51:12.673663 7f2461feb700 10 chain_cache_entry: cache_locator=.rgw+.bucket.meta.tcga:default.712449.19
2016-11-21 16:51:12.673685 7f2461feb700 15 decode_policy Read AccessControlPolicy<AccessControlPolicy xmlns="http://s3.amazonaws.com/doc/2006-03-01/";><Owner><ID>jmcdonal</ID><DisplayName>Jeffrey McDonald</DisplayName></Owner><AccessControlList><Grant><Grantee xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"; xsi:type="CanonicalUser"><ID>jmcdonal</ID><DisplayName>Jeffrey McDonald</DisplayName></Grantee><Permission>FULL_CONTROL</Permission></Grant></AccessControlList></AccessControlPolicy>
2016-11-21 16:51:12.673713 7f2461feb700 2 req 36:0.018343:s3:GET /:list_bucket:recalculating target
2016-11-21 16:51:12.673718 7f2461feb700 2 req 36:0.018348:s3:GET /:list_bucket:reading permissions
2016-11-21 16:51:12.673720 7f2461feb700 2 req 36:0.018350:s3:GET /:list_bucket:init op
2016-11-21 16:51:12.673723 7f2461feb700 2 req 36:0.018353:s3:GET /:list_bucket:verifying op mask
2016-11-21 16:51:12.673725 7f2461feb700 20 required_mask= 1 user.op_mask=7
2016-11-21 16:51:12.673726 7f2461feb700 2 req 36:0.018356:s3:GET /:list_bucket:verifying op permissions
2016-11-21 16:51:12.673734 7f2461feb700 5 Searching permissions for uid=jmcdonal mask=49
2016-11-21 16:51:12.673736 7f2461feb700 5 Found permission: 15
2016-11-21 16:51:12.673738 7f2461feb700 5 Searching permissions for group=1 mask=49
2016-11-21 16:51:12.673739 7f2461feb700 5 Permissions for group not found
2016-11-21 16:51:12.673740 7f2461feb700 5 Searching permissions for group=2 mask=49
2016-11-21 16:51:12.673742 7f2461feb700 5 Permissions for group not found
2016-11-21 16:51:12.673742 7f2461feb700 5 Getting permissions id=jmcdonal owner=jmcdonal perm=1
2016-11-21 16:51:12.673744 7f2461feb700 10 uid=jmcdonal requested perm (type)=1, policy perm=1, user_perm_mask=1, acl perm=1
2016-11-21 16:51:12.673745 7f2461feb700 2 req 36:0.018376:s3:GET /:list_bucket:verifying op params
2016-11-21 16:51:12.673748 7f2461feb700 2 req 36:0.018378:s3:GET /:list_bucket:pre-executing
2016-11-21 16:51:12.673750 7f2461feb700 2 req 36:0.018380:s3:GET /:list_bucket:executing
2016-11-21 16:51:12.673768 7f2461feb700 10 cls_bucket_list tcga(@{i=.rgw.buckets.index,e=.rgw.buckets.extra}.rgw.buckets.ec42[default.712449.19]) start [] num_entries 1001
2016-11-21 16:51:12.673786 7f2461feb700 20 reading from .rgw:.bucket.meta.tcga:default.712449.19
2016-11-21 16:51:12.673794 7f2461feb700 20 get_system_obj_state: rctx=0x7f2461fe4040 obj=.rgw:.bucket.meta.tcga:default.712449.19 state=0x7f26580242f8 s->prefetch_data=0
2016-11-21 16:51:12.673801 7f2461feb700 10 cache get: name=.rgw+.bucket.meta.tcga:default.712449.19 : type miss (requested=22, cached=19)
2016-11-21 16:51:12.673856 7f2461feb700 1 -- 128.101.189.204:0/2500521955 --> 10.31.0.66:6833/563585 -- osd_op(client.2588178.0:33 86.8c5e313b .bucket.meta.tcga:default.712449.19 [call version.read,getxattrs,stat] snapc 0=[] ack+read+known_if_redirected e455622) v7 -- ?+0 0x7f2658027080 con 0x7f265801eb60
2016-11-21 16:51:12.675000 7f2431ef1700 1 -- 128.101.189.204:0/2500521955 <== osd.245 10.31.0.66:6833/563585 3 ==== osd_op_reply(33 .bucket.meta.tcga:default.712449.19 [call,getxattrs,stat] v0'0 uv58800 ondisk = 0) v7 ==== 239+0+320 (3938913966 0 3388770584) 0x7f2474003130 con 0x7f265801eb60
2016-11-21 16:51:12.675119 7f2461feb700 10 cache put: name=.rgw+.bucket.meta.tcga:default.712449.19 info.flags=22
2016-11-21 16:51:12.675131 7f2461feb700 10 moving .rgw+.bucket.meta.tcga:default.712449.19 to cache LRU end
2016-11-21 16:51:12.675135 7f2461feb700 10 updating xattr: name=user.rgw.acl bl.length()=161
2016-11-21 16:51:12.675141 7f2461feb700 20 get_system_obj_state: s->obj_tag was set empty
2016-11-21 16:51:12.675147 7f2461feb700 10 cache get: name=.rgw+.bucket.meta.tcga:default.712449.19 : hit (requested=17, cached=23)
2016-11-21 16:51:12.675296 7f2461feb700 1 -- 128.101.189.204:0/2500521955 --> 10.31.0.70:6851/1771318 -- osd_op(client.2588178.0:34 100.4d86b68f .dir.default.712449.19 [call rgw.bucket_list] snapc 0=[] ack+read+known_if_redirected e455622) v7 -- ?+0 0x7f265802ac20 con 0x7f2658027150
2016-11-21 16:51:12.677417 7f2431cef700 1 -- 128.101.189.204:0/2500521955 <== osd.114 10.31.0.70:6851/1771318 1 ==== osd_op_reply(34 .dir.default.712449.19 [call] v0'0 uv0 ack = -2 ((2) No such file or directory)) v7 ==== 142+0+0 (2988442841 0 0) 0x7f2480005640 con 0x7f2658027150
2016-11-21 16:51:12.677651 7f2461feb700 2 req 36:0.022280:s3:GET /:list_bucket:completing
2016-11-21 16:51:12.677896 7f2461feb700 1 -- 128.101.189.204:0/2500521955 --> 10.31.0.71:6894/2671962 -- osd_op(client.2588178.0:35 99.34f668c4 2016-11-21-16-default.712449.19-tcga [append 0~203] snapc 0=[] ack+ondisk+write+known_if_redirected e455622) v7 -- ?+0 0x7f265802dd10 con 0x7f265802ae60
2016-11-21 16:51:12.677928 7f2461feb700 2 req 36:0.022558:s3:GET /:list_bucket:op status=-2
2016-11-21 16:51:12.677933 7f2461feb700 2 req 36:0.022564:s3:GET /:list_bucket:http status=404
2016-11-21 16:51:12.677943 7f2461feb700 1 ====== req done req=0x7f2461fe57d0 op status=-2 http_status=404 ======
2016-11-21 16:51:12.677960 7f2461feb700 20 process_request() returned -2
2016-11-21 16:51:12.677992 7f2461feb700 1 civetweb: 0x7f2658004150: 128.101.189.33 - - [21/Nov/2016:16:51:12 -0600] "GET / HTTP/1.1" 404 0 - -
2016-11-21 16:51:12.683175 7f2431aed700 1 -- 128.101.189.204:0/2500521955 <== osd.161 10.31.0.71:6894/2671962 1 ==== osd_op_reply(35 2016-11-21-16-default.712449.19-tcga [append 0~203] v455622'261469 uv281663 ack = 0) v7 ==== 156+0+0 (2435724229 0 0) 0x7f24940008c0 con 0x7f265802ae60
2016-11-21 16:51:12.683228 7f2431aed700 1 -- 128.101.189.204:0/2500521955 <== osd.161 10.31.0.71:6894/2671962 2 ==== osd_op_reply(35 2016-11-21-16-default.712449.19-tcga [append 0~203] v455622'261469 uv281663 ondisk = 0) v7 ==== 156+0+0 (2196148367 0 0) 0x7f24940008c0 con 0x7f265802ae60
_______________________________________________
ceph-users mailing list
ceph-users@xxxxxxxxxxxxxx
http://lists.ceph.com/listinfo.cgi/ceph-users-ceph.com
