Project

General

Profile

Actions

Bug #37270

closed

radosgw response 500 error while putting object

Added by 伟杰 谭 over 5 years ago. Updated over 5 years ago.

Status:
Closed
Priority:
Normal
Assignee:
-
Target version:
-
% Done:

0%

Source:
Tags:
Backport:
Regression:
No
Severity:
3 - minor
Reviewed:
Affected Versions:
ceph-qa-suite:
rgw
Pull request ID:
Crash signature (v1):
Crash signature (v2):

Description

My env is :
[tanweijie@gz-ceph-52-203 ~]$ cat /etc/redhat-release
CentOS Linux release 7.2.1511 (Core)
[tanweijie@gz-ceph-52-203 ~]$ sudo ceph -v
ceph version 12.2.7 (3ec878d1e53e1aeb47a9f619c49d9e7c0aa384d5) luminous (stable)
[tanweijie@gz-ceph-52-203 ~]$

2018-11-15 16:32:25.897665 7f187d57d700 1 ====== starting new request req=0x7f187d577110 =====
2018-11-15 16:32:25.897677 7f187d57d700 2 req 67835212:0.000011::PUT /2018-11-15-16/599a5b2f483442afa8fa65d8/15422706636870.6152642808670665::initializing for trans_id = tx0000000000000040b154c-005bed2f19-4a9157-tupu-201-zone1
2018-11-15 16:32:25.897683 7f187d57d700 10 rgw api priority: s3=5 s3website=4
2018-11-15 16:32:25.897684 7f187d57d700 10 host=172.26.2.58
2018-11-15 16:32:25.897685 7f187d57d700 20 subdomain= domain= in_hosted_domain=0 in_hosted_domain_s3website=0
2018-11-15 16:32:25.897687 7f187d57d700 20 final domain/bucket subdomain= domain= in_hosted_domain=0 in_hosted_domain_s3website=0 s->info.domain= s->info.request_uri=/2018-11-15-16/599a5b2f483442afa8fa65d8/15422706636870.6152642808670665
2018-11-15 16:32:25.897694 7f187d57d700 10 meta>> HTTP_X_AMZ_CONTENT_SHA256
2018-11-15 16:32:25.897697 7f187d57d700 10 meta>> HTTP_X_AMZ_DATE
2018-11-15 16:32:25.897699 7f187d57d700 10 x>> x-amz-content-sha256:dc3e238b80e8d3e945a2e56069aa5d8075102b31c518a9b70b33c8710585e4e8
2018-11-15 16:32:25.897701 7f187d57d700 10 x>> x-amz-date:20181115T083208Z
2018-11-15 16:32:25.897709 7f187d57d700 20 get_handler handler=22RGWHandler_REST_Obj_S3
2018-11-15 16:32:25.897711 7f187d57d700 10 handler=22RGWHandler_REST_Obj_S3
2018-11-15 16:32:25.897713 7f187d57d700 2 req 67835212:0.000047:s3:PUT /2018-11-15-16/599a5b2f483442afa8fa65d8/15422706636870.6152642808670665::getting op 1
2018-11-15 16:32:25.897720 7f187d57d700 10 op=21RGWPutObj_ObjStore_S3
2018-11-15 16:32:25.897721 7f187d57d700 2 req 67835212:0.000055:s3:PUT /2018-11-15-16/599a5b2f483442afa8fa65d8/15422706636870.6152642808670665:put_obj:verifying requester
2018-11-15 16:32:25.897723 7f187d57d700 20 rgw::auth::StrategyRegistry::s3_main_strategy_t: trying rgw::auth::s3::AWSAuthStrategy
2018-11-15 16:32:25.897724 7f187d57d700 20 rgw::auth::s3::AWSAuthStrategy: trying rgw::auth::s3::S3AnonymousEngine
2018-11-15 16:32:25.897726 7f187d57d700 20 rgw::auth::s3::S3AnonymousEngine denied with reason=-1
2018-11-15 16:32:25.897727 7f187d57d700 20 rgw::auth::s3::AWSAuthStrategy: trying rgw::auth::s3::LocalEngine
2018-11-15 16:32:25.897732 7f187d57d700 10 v4 signature format = 7ecb9afd29d38dd7413e004d44bbd5a00e399a8034f8bbb06c60dcc4cb564396
2018-11-15 16:32:25.897735 7f187d57d700 10 v4 credential format = HEREISMYACCESSKEY/20181115/us-east-1/s3/aws4_request
2018-11-15 16:32:25.897736 7f187d57d700 10 access key id = HEREISMYACCESSKEY
2018-11-15 16:32:25.897737 7f187d57d700 10 credential scope = 20181115/us-east-1/s3/aws4_request
2018-11-15 16:32:25.897749 7f187d57d700 10 canonical headers format = host:172.26.2.58:7480
x-amz-content-sha256:dc3e238b80e8d3e945a2e56069aa5d8075102b31c518a9b70b33c8710585e4e8
x-amz-date:20181115T083208Z

2018-11-15 16:32:25.897751 7f187d57d700 10 payload request hash = dc3e238b80e8d3e945a2e56069aa5d8075102b31c518a9b70b33c8710585e4e8
2018-11-15 16:32:25.897761 7f187d57d700 10 canonical request = PUT
/2018-11-15-16/599a5b2f483442afa8fa65d8/15422706636870.6152642808670665

host:172.26.2.58:7480
x-amz-content-sha256:dc3e238b80e8d3e945a2e56069aa5d8075102b31c518a9b70b33c8710585e4e8
x-amz-date:20181115T083208Z

host;x-amz-content-sha256;x-amz-date
dc3e238b80e8d3e945a2e56069aa5d8075102b31c518a9b70b33c8710585e4e8
2018-11-15 16:32:25.897762 7f187d57d700 10 canonical request hash = bc606bfc44d01f8db7d94686ff02abf3a642af84a885c5ae7936bc319ecd006a
2018-11-15 16:32:25.897772 7f187d57d700 10 string to sign = AWS4-HMAC-SHA256
20181115T083208Z
20181115/us-east-1/s3/aws4_request
bc606bfc44d01f8db7d94686ff02abf3a642af84a885c5ae7936bc319ecd006a
2018-11-15 16:32:25.897783 7f187d57d700 10 delaying v4 auth
2018-11-15 16:32:25.897849 7f187d57d700 10 date_k = ad45895410fc6277d9a3a70b2ed71d32e9834037482c2b6868f1fbf56f05b025
2018-11-15 16:32:25.897854 7f187d57d700 10 region_k = 60ed98f8c01c34bc2d806e1eb7f48c57961117dd9a7aa3f4a64d1e32b426a0a1
2018-11-15 16:32:25.897859 7f187d57d700 10 service_k = 7c782408bcdcc759be1f83d973ce833243076e707ec1422584b7f81b8c012f17
2018-11-15 16:32:25.897864 7f187d57d700 10 signing_k = b26c41194026c05feaf64bb514440e07d4ac2598fec27c13a9e41aca1babf4a1
2018-11-15 16:32:25.897886 7f187d57d700 10 generated signature = 7ecb9afd29d38dd7413e004d44bbd5a00e399a8034f8bbb06c60dcc4cb564396
2018-11-15 16:32:25.897887 7f187d57d700 15 string_to_sign=AWS4-HMAC-SHA256
20181115T083208Z
20181115/us-east-1/s3/aws4_request
bc606bfc44d01f8db7d94686ff02abf3a642af84a885c5ae7936bc319ecd006a
2018-11-15 16:32:25.897897 7f187d57d700 15 server signature=7ecb9afd29d38dd7413e004d44bbd5a00e399a8034f8bbb06c60dcc4cb564396
2018-11-15 16:32:25.897898 7f187d57d700 15 client signature=7ecb9afd29d38dd7413e004d44bbd5a00e399a8034f8bbb06c60dcc4cb564396
2018-11-15 16:32:25.897899 7f187d57d700 15 compare=0
2018-11-15 16:32:25.897903 7f187d57d700 20 rgw::auth::s3::LocalEngine granted access
2018-11-15 16:32:25.897904 7f187d57d700 20 rgw::auth::s3::AWSAuthStrategy granted access
2018-11-15 16:32:25.897907 7f187d57d700 2 req 67835212:0.000242:s3:PUT /2018-11-15-16/599a5b2f483442afa8fa65d8/15422706636870.6152642808670665:put_obj:normalizing buckets and tenants
2018-11-15 16:32:25.897910 7f187d57d700 10 s->object=599a5b2f483442afa8fa65d8/15422706636870.6152642808670665 s->bucket=2018-11-15-16
2018-11-15 16:32:25.897912 7f187d57d700 2 req 67835212:0.000246:s3:PUT /2018-11-15-16/599a5b2f483442afa8fa65d8/15422706636870.6152642808670665:put_obj:init permissions
2018-11-15 16:32:25.897925 7f187d57d700 15 decode_policy Read AccessControlPolicy<AccessControlPolicy xmlns="http://s3.amazonaws.com/doc/2006-03-01/&quot;&gt;&lt;Owner&gt;&lt;ID&gt;tupubi&lt;/ID&gt;&lt;DisplayName&gt;tupu-s3-system&lt;/DisplayName&gt;&lt;/Owner&gt;&lt;AccessControlList&gt;&lt;Grant&gt;&lt;Grantee xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance&quot; xsi:type="CanonicalUser"><ID>tupubi</ID><DisplayName>tupu-s3-system</DisplayName></Grantee><Permission>FULL_CONTROL</Permission></Grant></AccessControlList></AccessControlPolicy>
2018-11-15 16:32:25.897939 7f187d57d700 2 req 67835212:0.000274:s3:PUT /2018-11-15-16/599a5b2f483442afa8fa65d8/15422706636870.6152642808670665:put_obj:recalculating target
2018-11-15 16:32:25.897941 7f187d57d700 2 req 67835212:0.000276:s3:PUT /2018-11-15-16/599a5b2f483442afa8fa65d8/15422706636870.6152642808670665:put_obj:reading permissions
2018-11-15 16:32:25.897943 7f187d57d700 2 req 67835212:0.000278:s3:PUT /2018-11-15-16/599a5b2f483442afa8fa65d8/15422706636870.6152642808670665:put_obj:init op
2018-11-15 16:32:25.897945 7f187d57d700 2 req 67835212:0.000279:s3:PUT /2018-11-15-16/599a5b2f483442afa8fa65d8/15422706636870.6152642808670665:put_obj:verifying op mask
2018-11-15 16:32:25.897946 7f187d57d700 20 required_mask= 2 user.op_mask=7
2018-11-15 16:32:25.897947 7f187d57d700 2 req 67835212:0.000282:s3:PUT /2018-11-15-16/599a5b2f483442afa8fa65d8/15422706636870.6152642808670665:put_obj:verifying op permissions
2018-11-15 16:32:25.897949 7f187d57d700 20 -- Getting permissions begin with perm_mask=50
2018-11-15 16:32:25.897951 7f187d57d700 5 Searching permissions for identity=rgw::auth::SysReqApplier > rgw::auth::LocalApplier(acct_user=tupubi, acct_name=tupu-s3-system, subuser=, perm_mask=15, is_admin=0) mask=50
2018-11-15 16:32:25.897954 7f187d57d700 5 Searching permissions for uid=tupubi
2018-11-15 16:32:25.897955 7f187d57d700 5 Found permission: 15
2018-11-15 16:32:25.897958 7f187d57d700 5 Searching permissions for group=1 mask=50
2018-11-15 16:32:25.897959 7f187d57d700 5 Permissions for group not found
2018-11-15 16:32:25.897960 7f187d57d700 5 Searching permissions for group=2 mask=50
2018-11-15 16:32:25.897961 7f187d57d700 5 Permissions for group not found
2018-11-15 16:32:25.897962 7f187d57d700 5 -
Getting permissions done for identity=rgw::auth::SysReqApplier -> rgw::auth::LocalApplier(acct_user=tupubi, acct_name=tupu-s3-system, subuser=, perm_mask=15, is_admin=0), owner=tupubi, perm=2
2018-11-15 16:32:25.897964 7f187d57d700 10 identity=rgw::auth::SysReqApplier -> rgw::auth::LocalApplier(acct_user=tupubi, acct_name=tupu-s3-system, subuser=, perm_mask=15, is_admin=0) requested perm (type)=2, policy perm=2, user_perm_mask=2, acl perm=2
2018-11-15 16:32:25.897966 7f187d57d700 2 req 67835212:0.000300:s3:PUT /2018-11-15-16/599a5b2f483442afa8fa65d8/15422706636870.6152642808670665:put_obj:verifying op params
2018-11-15 16:32:25.897968 7f187d57d700 2 req 67835212:0.000302:s3:PUT /2018-11-15-16/599a5b2f483442afa8fa65d8/15422706636870.6152642808670665:put_obj:pre-executing
2018-11-15 16:32:25.897969 7f187d57d700 2 req 67835212:0.000303:s3:PUT /2018-11-15-16/599a5b2f483442afa8fa65d8/15422706636870.6152642808670665:put_obj:executing
2018-11-15 16:32:25.981901 7f184450b700 2 req 67833405:165.197798:s3:PUT /2018-11-15-16/599a5b2f483442afa8fa65d8/15422704985510.6297163260040779:put_obj:completing
2018-11-15 16:32:25.981915 7f184450b700 0 WARNING: set_req_state_err err_no=5 resorting to 500
2018-11-15 16:32:25.982003 7f184450b700 2 req 67833405:165.197902:s3:PUT /2018-11-15-16/599a5b2f483442afa8fa65d8/15422704985510.6297163260040779:put_obj:op status=-5
2018-11-15 16:32:25.982011 7f184450b700 2 req 67833405:165.197910:s3:PUT /2018-11-15-16/599a5b2f483442afa8fa65d8/15422704985510.6297163260040779:put_obj:http status=500
2018-11-15 16:32:25.982025 7f184450b700 1 ====== req done req=0x7f1844505110 op status=-5 http_status=500 ======
2018-11-15 16:32:25.982049 7f184450b700 20 process_request() returned -5
2018-11-15 16:32:25.983337 7f184450b700 1 civetweb: 0x7f18fc366000: 172.25.52.186 - - [15/Nov/2018:16:29:40 +0800] "PUT /2018-11-15-16/599a5b2f483442afa8fa65d8/15422704985510.6297163260040779 HTTP/1.1" 500 0 - aws-sdk-nodejs/2.262.1 linux/v8.9.3 promise
2018-11-15 16:32:25.983467 7f184450b700 20 CONTENT_LENGTH=373584
2018-11-15 16:32:25.983474 7f184450b700 20 CONTENT_TYPE=application/octet-stream
2018-11-15 16:32:25.983476 7f184450b700 20 HTTP_AUTHORIZATION=AWS4-HMAC-SHA256 Credential=HEREISMYACCESSKEY/20181115/us-east-1/s3/aws4_request, SignedHeaders=host;x-amz-content-sha256;x-amz-date, Signature=a7ad9fcf05040259956f952696f8f56ea2acdd32fffce0c9325f0b9ba405f7f6
2018-11-15 16:32:25.983480 7f184450b700 20 HTTP_CONNECTION=close
2018-11-15 16:32:25.983482 7f184450b700 20 HTTP_HOST=172.26.2.58:7480
2018-11-15 16:32:25.983485 7f184450b700 20 HTTP_USER_AGENT=aws-sdk-nodejs/2.262.1 linux/v8.9.3 promise
2018-11-15 16:32:25.983488 7f184450b700 20 HTTP_VERSION=1.1
2018-11-15 16:32:25.983490 7f184450b700 20 HTTP_X_AMZ_CONTENT_SHA256=2909e9c16ef46bc688b9a248a4885bc304b0168e56f4932d0b0b94d865c8b104
2018-11-15 16:32:25.983494 7f184450b700 20 HTTP_X_AMZ_DATE=20181115T083214Z
2018-11-15 16:32:25.983498 7f184450b700 20 REMOTE_ADDR=172.25.52.187
2018-11-15 16:32:25.983500 7f184450b700 20 REQUEST_METHOD=PUT
2018-11-15 16:32:25.983502 7f184450b700 20 REQUEST_URI=/2018-11-15-16/5b572e82878b01abf107dd7f/15422706736040.4062170427445626.jpg
2018-11-15 16:32:25.983505 7f184450b700 20 SCRIPT_URI=/2018-11-15-16/5b572e82878b01abf107dd7f/15422706736040.4062170427445626.jpg
2018-11-15 16:32:25.983506 7f184450b700 20 SERVER_PORT=7480

Actions

Also available in: Atom PDF