Project

General

Profile

Bug #18106

radosgw-admin-data-sync task fails with "object not deleted from destination zone"

Added by Casey Bodley about 6 years ago. Updated almost 6 years ago.

Status:
Resolved
Priority:
Normal
Target version:
-
% Done:

0%

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

Description

From http://qa-proxy.ceph.com/teuthology/teuthology-2016-11-28_17:05:19-rgw-master---basic-smithi/583185/teuthology.log:

2016-11-28T18:09:39.333 INFO:tasks.radosgw_agent.ubuntu@smithi072.front.sepia.ceph.com.8000.syncdaemon.smithi072.stderr:2016-11-28 18:09:39,333 24443 [radosgw_agent.sync][INFO  ] 127/128 items processed
2016-11-28T18:09:39.339 INFO:tasks.radosgw_agent.ubuntu@smithi072.front.sepia.ceph.com.8000.syncdaemon.smithi072.stderr:2016-11-28 18:09:39,339 27294 [radosgw_agent.worker][INFO  ] finished processing shard 127
2016-11-28T18:09:39.339 INFO:tasks.radosgw_agent.ubuntu@smithi072.front.sepia.ceph.com.8000.syncdaemon.smithi072.stderr:2016-11-28 18:09:39,339 24443 [radosgw_agent.sync][DEBUG ] synced item (127, []) successfully
2016-11-28T18:09:39.346 INFO:tasks.radosgw_agent.ubuntu@smithi072.front.sepia.ceph.com.8000.syncdaemon.smithi072.stderr:2016-11-28 18:09:39,346 24443 [radosgw_agent.sync][INFO  ] 128/128 items processed
2016-11-28T18:09:39.346 INFO:tasks.radosgw_agent.ubuntu@smithi072.front.sepia.ceph.com.8000.syncdaemon.smithi072.stderr:172.21.0.51 - - [28/Nov/2016 18:09:39] "POST /data/incremental HTTP/1.1" 200 0
2016-11-28T18:09:39.346 INFO:tasks.radosgw_agent.ubuntu@smithi072.front.sepia.ceph.com.8000.syncdaemon.smithi072.stderr:172.21.0.51 - - [28/Nov/2016 18:09:39] "POST /data/incremental HTTP/1.1" 200 -
2016-11-28T18:09:39.354 ERROR:teuthology.run_tasks:Saw exception from tasks.
Traceback (most recent call last):
  File "/home/teuthworker/src/teuthology_master/teuthology/run_tasks.py", line 86, in run_tasks
    manager = run_one_task(taskname, ctx=ctx, config=config)
  File "/home/teuthworker/src/teuthology_master/teuthology/run_tasks.py", line 65, in run_one_task
    return task(**kwargs)
  File "/home/teuthworker/src/ceph-qa-suite_master/tasks/radosgw_admin.py", line 493, in task
    assert dest_k == None, 'object not deleted from destination zone'
AssertionError: object not deleted from destination zone

Earlier in the radosgw-agent log, there are several instances of this error:

2016-11-28T18:07:28.946 INFO:tasks.radosgw_agent.ubuntu@smithi072.front.sepia.ceph.com.8000.syncdaemon.smithi072.stderr:2016-11-28 18:07:28,946 24443 [radosgw_agent.sync][INFO  ] 124/128 items processed
2016-11-28T18:07:38.393 INFO:tasks.radosgw_agent.ubuntu@smithi072.front.sepia.ceph.com.8000.syncdaemon.smithi072.stderr:2016-11-28 18:07:38,393 27294 [radosgw_agent.worker][DEBUG ] bucket instance "myfoodata:r0z0.4148.4" has 4 entries after " " 
2016-11-28T18:07:38.393 INFO:tasks.radosgw_agent.ubuntu@smithi072.front.sepia.ceph.com.8000.syncdaemon.smithi072.stderr:2016-11-28 18:07:38,393 27294 [radosgw_agent.worker][INFO  ] ********************************************************************************
2016-11-28T18:07:38.393 INFO:tasks.radosgw_agent.ubuntu@smithi072.front.sepia.ceph.com.8000.syncdaemon.smithi072.stderr:2016-11-28 18:07:38,393 27294 [radosgw_agent.worker][INFO  ] syncing bucket "myfoodata" 
2016-11-28T18:07:38.393 INFO:tasks.radosgw_agent.ubuntu@smithi072.front.sepia.ceph.com.8000.syncdaemon.smithi072.stderr:2016-11-28 18:07:38,393 27294 [radosgw_agent.worker][DEBUG ] syncing object myfoodata/tiny_file
2016-11-28T18:07:38.411 INFO:tasks.radosgw_agent.ubuntu@smithi072.front.sepia.ceph.com.8000.syncdaemon.smithi072.stderr:2016-11-28 18:07:38,411 27294 [radosgw_agent.worker][WARNING] encountered an error during sync: Http error code 403 content Forbidden

History

#1 Updated by Casey Bodley about 6 years ago

from the 'destination zone', rgw.client.1.log:

2016-11-28 18:07:38.403715 7f5af189f700 20 RGWEnv::set(): HTTP_DATE: Mon Nov 28 18:07:38 2016
2016-11-28 18:07:38.403721 7f5af189f700 20 RGWEnv::set(): HTTP_DEST_ZONE_SHORT_ID: 1973260594
2016-11-28 18:07:38.403722 7f5af189f700 20 RGWEnv::set(): HTTP_IF_MODIFIED_SINCE: 2016-11-28 18:01:55.550557061Z
2016-11-28 18:07:38.403724 7f5af189f700 20 RGWEnv::set(): HTTP_X_AMZ_COPY_SOURCE: myfoodata/tiny_file
2016-11-28 18:07:38.403728 7f5af189f700 10 meta>> HTTP_X_AMZ_COPY_SOURCE
2016-11-28 18:07:38.403731 7f5af189f700 10 x>> x-amz-copy-source:myfoodata/tiny_file
2016-11-28 18:07:38.403733 7f5af189f700 20 > HTTP_DATE -> Mon Nov 28 18:07:38 2016
2016-11-28 18:07:38.403735 7f5af189f700 20 > HTTP_DEST_ZONE_SHORT_ID -> 1973260594
2016-11-28 18:07:38.403736 7f5af189f700 20 > HTTP_IF_MODIFIED_SINCE -> 2016-11-28 18:01:55.550557061Z
2016-11-28 18:07:38.403737 7f5af189f700 20 > HTTP_X_AMZ_COPY_SOURCE -> myfoodata/tiny_file
2016-11-28 18:07:38.403745 7f5af189f700 10 get_canon_resource(): dest=/myfoodata/tiny_file
2016-11-28 18:07:38.403747 7f5af189f700 10 generated canonical header: GET

Mon Nov 28 18:07:38 2016
x-amz-copy-source:myfoodata/tiny_file
/myfoodata/tiny_file
2016-11-28 18:07:38.403787 7f5af189f700 15 generated auth header: AWS 1te6NH5mcdcq0Tc5i8i3:+GXcrjQxZZXVQy/Ww1xKIRrK9eY=
2016-11-28 18:07:38.403805 7f5af189f700 20 sending request to http://smithi072.front.sepia.ceph.com:7280/myfoodata/tiny_file?rgwx-uid=client1-system-user&rgwx-zonegroup=region0&rgwx-prepend-metadata=region0
2016-11-28 18:07:38.403828 7f5af189f700 20 register_request mgr=0x7f5b3b9582b0 req_data->id=0, easy_handle=0x7f5b3adb6000
2016-11-28 18:07:38.403834 7f5af189f700 20 link_request req_data=0x7f5b3a930e00 req_data->id=0, easy_handle=0x7f5b3adb6000
2016-11-28 18:07:38.407712 7f5af189f700 10 receive_http_header
2016-11-28 18:07:38.407722 7f5af189f700 10 received header:HTTP/1.1 403 Forbidden
2016-11-28 18:07:38.407727 7f5af189f700 10 receive_http_header
2016-11-28 18:07:38.407728 7f5af189f700 10 received header:Content-Length: 213
2016-11-28 18:07:38.407735 7f5af189f700 10 receive_http_header
2016-11-28 18:07:38.407736 7f5af189f700 10 received header:x-amz-request-id: tx00000000000000000046e-00583c726a-1034-r0z0
2016-11-28 18:07:38.407740 7f5af189f700 10 receive_http_header
2016-11-28 18:07:38.407741 7f5af189f700 10 received header:Accept-Ranges: bytes
2016-11-28 18:07:38.407745 7f5af189f700 10 receive_http_header
2016-11-28 18:07:38.407746 7f5af189f700 10 received header:Content-Type: application/xml
2016-11-28 18:07:38.407749 7f5af189f700 10 receive_http_header
2016-11-28 18:07:38.407750 7f5af189f700 10 received header:Date: Mon, 28 Nov 2016 18:07:38 GMT
2016-11-28 18:07:38.407753 7f5af189f700 10 receive_http_header
2016-11-28 18:07:38.407754 7f5af189f700 10 received header:

from the 'source zone', rgw.client.0.log:

2016-11-28 18:09:09.073260 7f84f90e6700  5 Searching permissions for identity=RGWThirdPartyAccountAuthApplier() -> RGWLocalAuthApplier(acct_user=client1-system-user, acct_name=client1-system-user, subuser=, perm_mask=15, is_admin=\00) mask=49
2016-11-28 18:09:09.073266 7f84f90e6700  5 Searching permissions for uid=client1-system-user
2016-11-28 18:09:09.073267 7f84f90e6700  5 Permissions for user not found
2016-11-28 18:09:09.073269 7f84f90e6700  5 Searching permissions for group=1 mask=49
2016-11-28 18:09:09.073271 7f84f90e6700  5 Permissions for group not found
2016-11-28 18:09:09.073273 7f84f90e6700  5 Searching permissions for group=2 mask=49
2016-11-28 18:09:09.073274 7f84f90e6700  5 Permissions for group not found
2016-11-28 18:09:09.073275 7f84f90e6700  5 Getting permissions identity=RGWThirdPartyAccountAuthApplier() -> RGWLocalAuthApplier(acct_user=client1-system-user, acct_name=client1-system-user, subuser=, perm_mask=15, is_admin=\00) owner=foo perm=0
2016-11-28 18:09:09.073278 7f84f90e6700 10  identity=RGWThirdPartyAccountAuthApplier() -> RGWLocalAuthApplier(acct_user=client1-system-user, acct_name=client1-system-user, subuser=, perm_mask=15, is_admin=\00) requested perm (type)=1, policy perm=0, user_perm_mask=15, acl perm=0
2016-11-28 18:09:09.073284 7f84f90e6700 10 read_permissions on myfoodata(@{i=.region0.r0z0.index_pool,e=.region0.r0z0.data_extra_pool}.region0.r0z0.data_pool[r0z0.4148.4]):tiny_file only_bucket=0 ret=-13

The request is correctly identified as a system_request, but read_policy() in rgw_op.cc is returning -EACCESS without taking system_request into account.

#2 Updated by Orit Wasserman about 6 years ago

  • Assignee changed from Casey Bodley to Radoslaw Zarzynski

#3 Updated by Radoslaw Zarzynski about 6 years ago

  • Status changed from New to In Progress

#4 Updated by Radoslaw Zarzynski about 6 years ago

  • Status changed from In Progress to Fix Under Review

#5 Updated by Casey Bodley almost 6 years ago

  • Status changed from Fix Under Review to Resolved

Also available in: Atom PDF