Bug 1725130

Description of problem:


Version-Release number of selected component (if applicable):
ceph version 10.2.10-50.el7cp

How reproducible:
Intermittent

Steps to Reproduce:
1. Create 3 buckets having million+ objects, and having 100+ shards.
2. do a restart of the RGW daemon, and do some "s3cmd ls " commands. There are no failures observed.
3. Run the workload given Mark here : https://bugzilla.redhat.com/show_bug.cgi?id=1711392#c43
Command - "while [ true ]; do  ls -b 5* | xargs -n1 -P500 -i sh -c "echo {} ; nice s3cmd --multipart-chunk-size-mb=5 put {} s3://bucket1/{}__xxx002${i}"  ; done"
4. After the workload runs for 5-10 mins, the s3cmd ls command failing intermittently.

oot@magna010 ~]# s3cmd ls
2019-06-24 15:13  s3://bucket1
2019-06-24 15:15  s3://bucket2
2019-06-24 14:49  s3://ver1
[root@magna010 ~]# s3cmd ls
[root@magna010 ~]# 
[root@magna010 ~]# 
[root@magna010 ~]# s3cmd ls
2019-06-24 15:13  s3://bucket1
2019-06-24 15:15  s3://bucket2
2019-06-24 14:49  s3://ver1
[root@magna010 ~]# s3cmd ls
[root@magna010 ~]# s3cmd ls
2019-06-24 15:13  s3://bucket1
2019-06-24 15:15  s3://bucket2
2019-06-24 14:49  s3://ver1
[root@magna010 ~]# s3cmd ls
2019-06-24 15:13  s3://bucket1
2019-06-24 15:15  s3://bucket2
2019-06-24 14:49  s3://ver1
[root@magna010 ~]# s3cmd ls
root@magna010 ~]#

Similar results observed with AWSCLI also, so not a client issue.
Logs indicate a 200 OK result, so not sure what could be the cause here.


13:25:31.479790 7fed757ea700  1 ====== starting new request req=0x7fed757e46d0 =====
2019-06-28 13:25:31.479827 7fed757ea700  2 req 1485:0.000036::GET /::initializing for trans_id = tx0000000000000000005cd-005d16154b-196fa-default
2019-06-28 13:25:31.479841 7fed757ea700 10 rgw api priority: s3=5 s3website=4
2019-06-28 13:25:31.479844 7fed757ea700 10 host=magna010
2019-06-28 13:25:31.479848 7fed757ea700 20 subdomain= domain= in_hosted_domain=0 in_hosted_domain_s3website=0
2019-06-28 13:25:31.479852 7fed757ea700 20 final domain/bucket subdomain= domain= in_hosted_domain=0 in_hosted_domain_s3website=0 s->info.domain= s->info.request_uri=/
2019-06-28 13:25:31.479865 7fed757ea700 10 meta>> HTTP_X_AMZ_DATE
2019-06-28 13:25:31.479873 7fed757ea700 10 x>> x-amz-date:Fri, 28 Jun 2019 13:25:31 +0000
2019-06-28 13:25:31.479896 7fed757ea700 20 get_handler handler=26RGWHandler_REST_Service_S3
2019-06-28 13:25:31.479902 7fed757ea700 10 handler=26RGWHandler_REST_Service_S3
2019-06-28 13:25:31.479905 7fed757ea700  2 req 1485:0.000115:s3:GET /::getting op 0
2019-06-28 13:25:31.479910 7fed757ea700 10 op=26RGWListBuckets_ObjStore_S3
2019-06-28 13:25:31.479913 7fed757ea700  2 req 1485:0.000123:s3:GET /:list_buckets:authorizing
2019-06-28 13:25:31.479958 7fed757ea700 10 get_canon_resource(): dest=/
2019-06-28 13:25:31.479962 7fed757ea700 10 auth_hdr:
GET



x-amz-date:Fri, 28 Jun 2019 13:25:31 +0000
/
2019-06-28 13:25:31.480026 7fed757ea700 15 calculated digest=1XeslmixjYG81YD7FaYR4SsFdv4=
2019-06-28 13:25:31.480029 7fed757ea700 15 auth_sign=1XeslmixjYG81YD7FaYR4SsFdv4=
2019-06-28 13:25:31.480031 7fed757ea700 15 compare=0
2019-06-28 13:25:31.480034 7fed757ea700  2 req 1485:0.000244:s3:GET /:list_buckets:normalizing buckets and tenants
2019-06-28 13:25:31.480040 7fed757ea700 10 s->object=<NULL> s->bucket=
2019-06-28 13:25:31.480043 7fed757ea700  2 req 1485:0.000253:s3:GET /:list_buckets:init permissions
2019-06-28 13:25:31.480050 7fed757ea700  2 req 1485:0.000260:s3:GET /:list_buckets:recalculating target
2019-06-28 13:25:31.480053 7fed757ea700  2 req 1485:0.000264:s3:GET /:list_buckets:reading permissions
2019-06-28 13:25:31.480058 7fed757ea700  2 req 1485:0.000268:s3:GET /:list_buckets:init op
2019-06-28 13:25:31.480062 7fed757ea700  2 req 1485:0.000272:s3:GET /:list_buckets:verifying op mask
2019-06-28 13:25:31.480065 7fed757ea700 20 required_mask= 1 user.op_mask=7
2019-06-28 13:25:31.480067 7fed757ea700  2 req 1485:0.000277:s3:GET /:list_buckets:verifying op permissions
2019-06-28 13:25:31.480070 7fed757ea700  2 req 1485:0.000280:s3:GET /:list_buckets:verifying op params
2019-06-28 13:25:31.480074 7fed757ea700  2 req 1485:0.000283:s3:GET /:list_buckets:pre-executing
2019-06-28 13:25:31.480076 7fed757ea700  2 req 1485:0.000287:s3:GET /:list_buckets:executing
2019-06-28 13:25:31.481059 7fed757ea700  2 req 1485:0.001269:s3:GET /:list_buckets:completing
2019-06-28 13:25:31.481123 7fed757ea700  2 req 1485:0.001333:s3:GET /:list_buckets:op status=0
2019-06-28 13:25:31.481132 7fed757ea700  2 req 1485:0.001342:s3:GET /:list_buckets:http status=200
2019-06-28 13:25:31.481137 7fed757ea700  1 ====== req done req=0x7fed757e46d0 op status=0 http_status=200 ====

Setup is still intact for debugging.