Project

General

Profile

Bug #65436 ยป radosgw crash details (scrubbed).log

Full rgw log - Reid Guyett, 04/11/2024 05:10 PM

 
2024-04-11T11:02:38.174+0000 7f6bbf6ee700 20 REMOTE_ADDR=127.0.0.1
2024-04-11T11:02:38.174+0000 7f6bbf6ee700 20 REQUEST_METHOD=GET
2024-04-11T11:02:38.174+0000 7f6bbf6ee700 20 REQUEST_URI=/.cache/<scrubbed 112 characters>.jpg/<scrubbed 33characters>
2024-04-11T11:02:38.174+0000 7f6bbf6ee700 20 SCRIPT_URI=/.cache/<scrubbed 112 characters>.jpg/<scrubbed 33characters>
2024-04-11T11:02:38.174+0000 7f6bbf6ee700 20 SERVER_PORT=7480
2024-04-11T11:02:38.174+0000 7f6bbf6ee700 1 ====== starting new request req=0x7f6fb47f7740 =====
2024-04-11T11:02:38.174+0000 7f6bbf6ee700 2 req 1201706618685104296 0.000000000s initializing for trans_id = tx0000010ad51cd82f620a8-006617c34e-30ca2c1a-<scrubbed zone>
2024-04-11T11:02:38.174+0000 7f6bbf6ee700 10 req 1201706618685104296 0.000000000s rgw api priority: s3=4 s3website=-1
2024-04-11T11:02:38.174+0000 7f6bbf6ee700 10 req 1201706618685104296 0.000000000s host=<scrubbed bucketname>.<scrubbed FQDN>
2024-04-11T11:02:38.174+0000 7f6bbf6ee700 20 req 1201706618685104296 0.000000000s subdomain=<scrubbed bucketname> domain=<scrubbed FQDN> in_hosted_domain=1 in_hosted_domain_s3website=0
2024-04-11T11:02:38.174+0000 7f6bbf6ee700 20 req 1201706618685104296 0.000000000s final domain/bucket subdomain=<scrubbed bucketname> domain=<scrubbed FQDN> in_hosted_domain=1 in_hosted_domain_s3website=0 s->info.domain=<scrubbed FQDN> s->info.request_uri=/<scrubbed bucketname>/.cache/<scrubbed 112 characters>.jpg/<scrubbed 33characters>
2024-04-11T11:02:38.174+0000 7f6bbf6ee700 10 req 1201706618685104296 0.000000000s meta>> HTTP_X_AMZ_CONTENT_SHA256
2024-04-11T11:02:38.174+0000 7f6bbf6ee700 10 req 1201706618685104296 0.000000000s meta>> HTTP_X_AMZ_DATE
2024-04-11T11:02:38.174+0000 7f6bbf6ee700 10 req 1201706618685104296 0.000000000s meta>> HTTP_X_AMZ_USER_AGENT
2024-04-11T11:02:38.174+0000 7f6bbf6ee700 10 req 1201706618685104296 0.000000000s x>> x-amz-content-sha256:<scrubbed hash>
2024-04-11T11:02:38.174+0000 7f6bbf6ee700 10 req 1201706618685104296 0.000000000s x>> x-amz-date:20240411T110238Z
2024-04-11T11:02:38.174+0000 7f6bbf6ee700 10 req 1201706618685104296 0.000000000s x>> x-amz-user-agent:aws-sdk-php/3.215.1
2024-04-11T11:02:38.174+0000 7f6bbf6ee700 20 req 1201706618685104296 0.000000000s get_handler handler=22RGWHandler_REST_Obj_S3
2024-04-11T11:02:38.174+0000 7f6bbf6ee700 10 req 1201706618685104296 0.000000000s handler=22RGWHandler_REST_Obj_S3
2024-04-11T11:02:38.174+0000 7f6bbf6ee700 2 req 1201706618685104296 0.000000000s getting op 0
2024-04-11T11:02:38.174+0000 7f6bbf6ee700 20 req 1201706618685104296 0.000000000s get_system_obj_state: rctx=0x7f6fb47f67b0 obj=<scrubbed log_pool_name>:script.prerequest. state=0x7f6fb92870a0 s->prefetch_data=0
2024-04-11T11:02:38.174+0000 7f6bbf6ee700 10 req 1201706618685104296 0.000000000s cache get: name=<scrubbed log_pool_name>++script.prerequest. : hit (negative entry)
2024-04-11T11:02:38.174+0000 7f6bbf6ee700 10 req 1201706618685104296 0.000000000s s3:get_obj scheduling with throttler client=2 cost=1
2024-04-11T11:02:38.174+0000 7f6bbf6ee700 10 req 1201706618685104296 0.000000000s s3:get_obj op=21RGWGetObj_ObjStore_S3
2024-04-11T11:02:38.174+0000 7f6bbf6ee700 2 req 1201706618685104296 0.000000000s s3:get_obj verifying requester
2024-04-11T11:02:38.174+0000 7f6bbf6ee700 20 req 1201706618685104296 0.000000000s s3:get_obj rgw::auth::StrategyRegistry::s3_main_strategy_t: trying rgw::auth::s3::AWSAuthStrategy
2024-04-11T11:02:38.174+0000 7f6bbf6ee700 20 req 1201706618685104296 0.000000000s s3:get_obj rgw::auth::s3::AWSAuthStrategy: trying rgw::auth::s3::S3AnonymousEngine
2024-04-11T11:02:38.174+0000 7f6bbf6ee700 20 req 1201706618685104296 0.000000000s s3:get_obj rgw::auth::s3::S3AnonymousEngine denied with reason=-1
2024-04-11T11:02:38.174+0000 7f6bbf6ee700 20 req 1201706618685104296 0.000000000s s3:get_obj rgw::auth::s3::AWSAuthStrategy: trying rgw::auth::s3::LocalEngine
2024-04-11T11:02:38.174+0000 7f6bbf6ee700 10 req 1201706618685104296 0.000000000s v4 signature format = <scrubbed hash>
2024-04-11T11:02:38.174+0000 7f6bbf6ee700 10 req 1201706618685104296 0.000000000s v4 credential format = <scrubbed access_key>/20240411/<scrubbed FQDN>/s3/aws4_request
2024-04-11T11:02:38.174+0000 7f6bbf6ee700 10 req 1201706618685104296 0.000000000s access key id = <scrubbed access_key>
2024-04-11T11:02:38.174+0000 7f6bbf6ee700 10 req 1201706618685104296 0.000000000s credential scope = 20240411/<scrubbed FQDN>/s3/aws4_request
2024-04-11T11:02:38.174+0000 7f6bbf6ee700 10 req 1201706618685104296 0.000000000s canonical headers format = host:<scrubbed bucketname>.<scrubbed FQDN>
2024-04-11T11:02:38.174+0000 7f6bbf6ee700 10 req 1201706618685104296 0.000000000s payload request hash = <scrubbed hash>
2024-04-11T11:02:38.174+0000 7f6bbf6ee700 10 req 1201706618685104296 0.000000000s canonical request = GET
2024-04-11T11:02:38.174+0000 7f6bbf6ee700 10 req 1201706618685104296 0.000000000s canonical request hash = <scrubbed hash>
2024-04-11T11:02:38.174+0000 7f6bbf6ee700 10 req 1201706618685104296 0.000000000s string to sign = AWS4-HMAC-SHA256
2024-04-11T11:02:38.174+0000 7f6bbf6ee700 10 req 1201706618685104296 0.000000000s date_k = <scrubbed hash>
2024-04-11T11:02:38.174+0000 7f6bbf6ee700 10 req 1201706618685104296 0.000000000s region_k = <scrubbed hash>
2024-04-11T11:02:38.174+0000 7f6bbf6ee700 10 req 1201706618685104296 0.000000000s service_k = <scrubbed hash>
2024-04-11T11:02:38.174+0000 7f6bbf6ee700 10 req 1201706618685104296 0.000000000s signing_k = <scrubbed hash>
2024-04-11T11:02:38.174+0000 7f6bbf6ee700 10 req 1201706618685104296 0.000000000s generated signature = <scrubbed hash>
2024-04-11T11:02:38.174+0000 7f6bbf6ee700 15 req 1201706618685104296 0.000000000s s3:get_obj string_to_sign=AWS4-HMAC-SHA256
2024-04-11T11:02:38.174+0000 7f6bbf6ee700 15 req 1201706618685104296 0.000000000s s3:get_obj server signature=<scrubbed hash>
2024-04-11T11:02:38.174+0000 7f6bbf6ee700 15 req 1201706618685104296 0.000000000s s3:get_obj client signature=<scrubbed hash>
2024-04-11T11:02:38.174+0000 7f6bbf6ee700 15 req 1201706618685104296 0.000000000s s3:get_obj compare=0
2024-04-11T11:02:38.174+0000 7f6bbf6ee700 20 req 1201706618685104296 0.000000000s s3:get_obj rgw::auth::s3::LocalEngine granted access
2024-04-11T11:02:38.174+0000 7f6bbf6ee700 20 req 1201706618685104296 0.000000000s s3:get_obj rgw::auth::s3::AWSAuthStrategy granted access
2024-04-11T11:02:38.174+0000 7f6bbf6ee700 2 req 1201706618685104296 0.000000000s s3:get_obj normalizing buckets and tenants
2024-04-11T11:02:38.174+0000 7f6bbf6ee700 10 req 1201706618685104296 0.000000000s s->object=.cache/<scrubbed 112 characters>.jpg/<scrubbed 33characters> s->bucket=<scrubbed bucketname>
2024-04-11T11:02:38.174+0000 7f6bbf6ee700 2 req 1201706618685104296 0.000000000s s3:get_obj init permissions
2024-04-11T11:02:38.174+0000 7f6bbf6ee700 20 req 1201706618685104296 0.000000000s s3:get_obj get_system_obj_state: rctx=0x7f6fb47f61e0 obj=<scrubbed meta_pool_name>:root:<scrubbed bucketname> state=0x7f6fb92870a0 s->prefetch_data=0
2024-04-11T11:02:38.174+0000 7f6bbf6ee700 10 req 1201706618685104296 0.000000000s s3:get_obj cache get: name=<scrubbed meta_pool_name>+root+<scrubbed bucketname> : hit (requested=0x16, cached=0x17)
2024-04-11T11:02:38.174+0000 7f6bbf6ee700 20 req 1201706618685104296 0.000000000s s3:get_obj get_system_obj_state: s->obj_tag was set empty
2024-04-11T11:02:38.174+0000 7f6bbf6ee700 10 req 1201706618685104296 0.000000000s s3:get_obj cache get: name=<scrubbed meta_pool_name>+root+<scrubbed bucketname> : hit (requested=0x11, cached=0x17)
2024-04-11T11:02:38.174+0000 7f6bbf6ee700 15 req 1201706618685104296 0.000000000s s3:get_obj decode_policy Read AccessControlPolicy<AccessControlPolicy xmlns="http://s3.amazonaws.com/doc/2006-03-01/"><Owner><ID><scrubbed user_id></ID><DisplayName><scrubbed user_id></DisplayName></Owner><AccessControlList><Grant><Grantee xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance" xsi:type="CanonicalUser"><ID><scrubbed user_id></ID><DisplayName><scrubbed user_id></DisplayName></Grantee><Permission>FULL_CONTROL</Permission></Grant></AccessControlList></AccessControlPolicy>
2024-04-11T11:02:38.174+0000 7f6bbf6ee700 20 req 1201706618685104296 0.000000000s s3:get_obj get_system_obj_state: rctx=0x7f6fb47f5c88 obj=<scrubbed meta_pool_name>:users.uid:<scrubbed user_id> state=0x7f6fb92870a0 s->prefetch_data=0
2024-04-11T11:02:38.174+0000 7f6bbf6ee700 10 req 1201706618685104296 0.000000000s s3:get_obj cache get: name=<scrubbed meta_pool_name>+users.uid+<scrubbed user_id> : hit (requested=0x16, cached=0x17)
2024-04-11T11:02:38.174+0000 7f6bbf6ee700 20 req 1201706618685104296 0.000000000s s3:get_obj get_system_obj_state: s->obj_tag was set empty
2024-04-11T11:02:38.174+0000 7f6bbf6ee700 20 req 1201706618685104296 0.000000000s s3:get_obj Read xattr: user.rgw.idtag
2024-04-11T11:02:38.174+0000 7f6bbf6ee700 10 req 1201706618685104296 0.000000000s s3:get_obj cache get: name=<scrubbed meta_pool_name>+users.uid+<scrubbed user_id> : hit (requested=0x13, cached=0x17)
2024-04-11T11:02:38.174+0000 7f6bbf6ee700 2 req 1201706618685104296 0.000000000s s3:get_obj recalculating target
2024-04-11T11:02:38.174+0000 7f6bbf6ee700 2 req 1201706618685104296 0.000000000s s3:get_obj reading permissions
2024-04-11T11:02:38.174+0000 7f6bbf6ee700 20 req 1201706618685104296 0.000000000s s3:get_obj get_obj_state: rctx=0x7f6fb47f6ac0 obj=<scrubbed bucketname>:.cache/<scrubbed 112 characters>.jpg/<scrubbed 33characters> state=0x7f698418d728 s->prefetch_data=1
2024-04-11T11:02:38.174+0000 7f6bbf6ee700 20 req 1201706618685104296 0.000000000s s3:get_obj WARNING: blocking librados call
2024-04-11T11:02:38.174+0000 7f6bbf6ee700 1 -- <scrubbed osd_ip_address>:0/4276705093 --> [v2:<scrubbed osd_ip_address2>:6888/217943,v1:<scrubbed osd_ip_address2>:6889/217943] -- osd_op(unknown.0.0:729581 5.5c1s0 5:83b3c5a8:::5e9bc383-f7bd-4fd1-b607-1e563bfe0011.341062507.6_.cache%2f<scrubbed 112 characters>.jpg%2f<scrubbed 33characters>:head [getxattrs,stat,read 0~4194304] snapc 0=[] ondisk+read+known_if_redirected+supports_pool_eio e113733) v8 -- 0x7f69840d31e0 con 0x7f6f4c00a0e0
2024-04-11T11:02:38.174+0000 7f6fbd8ed700 1 -- <scrubbed osd_ip_address>:0/4276705093 <== osd.177 v2:<scrubbed osd_ip_address2>:6888/217943 4172 ==== osd_op_reply(729581 5e9bc383-f7bd-4fd1-b607-1e563bfe0011.341062507.6_.cache/<scrubbed 112 characters>.jpg/<scrubbed 33characters> [getxattrs out=423b,stat out=16b,read 0~0] v0'0 uv5357760 ondisk = 0) v8 ==== 432+0+439 (crc 0 0 0) 0x7f6fb00db040 con 0x7f6f4c00a0e0
2024-04-11T11:02:38.174+0000 7f6bbf6ee700 20 req 1201706618685104296 0.000000000s s3:get_obj get_obj_state: s->obj_tag was set empty
2024-04-11T11:02:38.174+0000 7f6bbf6ee700 20 req 1201706618685104296 0.000000000s s3:get_obj get_obj_state_impl: setting s->olh_tag to mzwwfosvk0waiqax35sxs4uzxraeetuq
2024-04-11T11:02:38.174+0000 7f6bbf6ee700 20 req 1201706618685104296 0.000000000s s3:get_obj get_obj_state: rctx=0x7f6fb47f6ac0 obj=<scrubbed bucketname>:.cache/<scrubbed 112 characters>.jpg/<scrubbed 33characters> state=0x7f698418d728 s->prefetch_data=1
2024-04-11T11:02:38.174+0000 7f6bbf6ee700 0 req 1201706618685104296 0.000000000s s3:get_obj WARNING: couldn't find acl header for object, generating default
2024-04-11T11:02:38.174+0000 7f6bbf6ee700 20 req 1201706618685104296 0.000000000s s3:get_obj get_system_obj_state: rctx=0x7f6fb47f5e98 obj=<scrubbed meta_pool_name>:users.uid:<scrubbed user_id> state=0x7f6fb92870a0 s->prefetch_data=0
2024-04-11T11:02:38.174+0000 7f6bbf6ee700 10 req 1201706618685104296 0.000000000s s3:get_obj cache get: name=<scrubbed meta_pool_name>+users.uid+<scrubbed user_id> : hit (requested=0x16, cached=0x17)
2024-04-11T11:02:38.174+0000 7f6bbf6ee700 20 req 1201706618685104296 0.000000000s s3:get_obj get_system_obj_state: s->obj_tag was set empty
2024-04-11T11:02:38.174+0000 7f6bbf6ee700 20 req 1201706618685104296 0.000000000s s3:get_obj Read xattr: user.rgw.idtag
2024-04-11T11:02:38.174+0000 7f6bbf6ee700 10 req 1201706618685104296 0.000000000s s3:get_obj cache get: name=<scrubbed meta_pool_name>+users.uid+<scrubbed user_id> : hit (requested=0x13, cached=0x17)
2024-04-11T11:02:38.174+0000 7f6bbf6ee700 2 req 1201706618685104296 0.000000000s s3:get_obj init op
2024-04-11T11:02:38.174+0000 7f6bbf6ee700 2 req 1201706618685104296 0.000000000s s3:get_obj verifying op mask
2024-04-11T11:02:38.174+0000 7f6bbf6ee700 20 req 1201706618685104296 0.000000000s s3:get_obj required_mask= 1 user.op_mask=7
2024-04-11T11:02:38.174+0000 7f6bbf6ee700 2 req 1201706618685104296 0.000000000s s3:get_obj verifying op permissions
2024-04-11T11:02:38.174+0000 7f6bbf6ee700 20 req 1201706618685104296 0.000000000s s3:get_obj -- Getting permissions begin with perm_mask=49
2024-04-11T11:02:38.174+0000 7f6bbf6ee700 5 req 1201706618685104296 0.000000000s s3:get_obj Searching permissions for identity=rgw::auth::SysReqApplier -> rgw::auth::LocalApplier(acct_user=<scrubbed user_id>, acct_name=<scrubbed user_id>, subuser=, perm_mask=15, is_admin=0) mask=49
2024-04-11T11:02:38.174+0000 7f6bbf6ee700 5 req 1201706618685104296 0.000000000s s3:get_obj Searching permissions for uid=<scrubbed user_id>
2024-04-11T11:02:38.174+0000 7f6bbf6ee700 5 req 1201706618685104296 0.000000000s s3:get_obj Found permission: 15
2024-04-11T11:02:38.174+0000 7f6bbf6ee700 5 req 1201706618685104296 0.000000000s s3:get_obj Searching permissions for group=1 mask=49
2024-04-11T11:02:38.174+0000 7f6bbf6ee700 5 req 1201706618685104296 0.000000000s s3:get_obj Permissions for group not found
2024-04-11T11:02:38.174+0000 7f6bbf6ee700 5 req 1201706618685104296 0.000000000s s3:get_obj Searching permissions for group=2 mask=49
2024-04-11T11:02:38.174+0000 7f6bbf6ee700 5 req 1201706618685104296 0.000000000s s3:get_obj Permissions for group not found
2024-04-11T11:02:38.174+0000 7f6bbf6ee700 5 req 1201706618685104296 0.000000000s s3:get_obj -- Getting permissions done for identity=rgw::auth::SysReqApplier -> rgw::auth::LocalApplier(acct_user=<scrubbed user_id>, acct_name=<scrubbed user_id>, subuser=, perm_mask=15, is_admin=0), owner=<scrubbed user_id>, perm=1
2024-04-11T11:02:38.174+0000 7f6bbf6ee700 10 req 1201706618685104296 0.000000000s s3:get_obj identity=rgw::auth::SysReqApplier -> rgw::auth::LocalApplier(acct_user=<scrubbed user_id>, acct_name=<scrubbed user_id>, subuser=, perm_mask=15, is_admin=0) requested perm (type)=1, policy perm=1, user_perm_mask=15, acl perm=1
2024-04-11T11:02:38.174+0000 7f6bbf6ee700 2 req 1201706618685104296 0.000000000s s3:get_obj verifying op params
2024-04-11T11:02:38.174+0000 7f6bbf6ee700 2 req 1201706618685104296 0.000000000s s3:get_obj pre-executing
2024-04-11T11:02:38.174+0000 7f6bbf6ee700 2 req 1201706618685104296 0.000000000s s3:get_obj check rate limiting
2024-04-11T11:02:38.174+0000 7f6bbf6ee700 2 req 1201706618685104296 0.000000000s s3:get_obj executing
2024-04-11T11:02:38.174+0000 7f6bbf6ee700 20 req 1201706618685104296 0.000000000s s3:get_obj get_obj_state: rctx=0x7f6fb47f6ac0 obj=<scrubbed bucketname>:.cache/<scrubbed 112 characters>.jpg/<scrubbed 33characters> state=0x7f698418d728 s->prefetch_data=1
2024-04-11T11:02:38.174+0000 7f6bbf6ee700 20 req 1201706618685104296 0.000000000s s3:get_obj get_obj_state: rctx=0x7f6fb47f6ac0 obj=<scrubbed bucketname>:.cache/<scrubbed 112 characters>.jpg/<scrubbed 33characters> state=0x7f698418d728 s->prefetch_data=1
2024-04-11T11:02:38.174+0000 7f6bbf6ee700 20 req 1201706618685104296 0.000000000s s3:get_obj Read xattr rgw_rados: user.rgw.idtag
2024-04-11T11:02:38.174+0000 7f6bbf6ee700 20 req 1201706618685104296 0.000000000s s3:get_obj Read xattr rgw_rados: user.rgw.manifest
2024-04-11T11:02:38.174+0000 7f6bbf6ee700 20 req 1201706618685104296 0.000000000s s3:get_obj Read xattr rgw_rados: user.rgw.olh.idtag
2024-04-11T11:02:38.174+0000 7f6bbf6ee700 20 req 1201706618685104296 0.000000000s s3:get_obj Read xattr rgw_rados: user.rgw.olh.info
2024-04-11T11:02:38.174+0000 7f6bbf6ee700 20 req 1201706618685104296 0.000000000s s3:get_obj Read xattr rgw_rados: user.rgw.olh.ver
2024-04-11T11:02:38.178+0000 7f6bbf6ee700 -1 *** Caught signal (Aborted) **

    (1-1/1)