9 Apr
2020
9 Apr
'20
12:44 a.m.
Hello,
I'm running a cluster with Ceph version 14.2.7
(3d58626ebeec02d8385a4cefb92c6cbc3a45bfe8) nautilus (stable).
I've encountered an issue with my cluster where objects are marked as expired but are
not removed during lifecycle processing. These buckets have a mix of objects with and
without special characters in their names. I set debug_rgw to 20/5 overnight so I could
get more detailed logs when the lifecycle processing happened. The lifecycle function
seems to correctly identify expired objects that should be removed, however they are not
deleted. This is happening across multiple buckets and users.
This cluster does have dynamic bucket index resharding enabled, however this issue affects
buckets regardless of their reshard status. I also have cache tiering set to readproxy for
the buckets data pool.
root@rgw01 # ceph daemon /var/run/ceph/ceph-rgw-rgw01.asok config show | grep -E
"lifecycle|lc"
"rgw_lifecycle_work_time": "00:00-06:00",
"rgw_enable_lc_threads": "true",
"rgw_lc_debug_interval": "-1",
"rgw_lc_lock_max_time": "60",
"rgw_lc_max_objs": "32",
"rgw_lc_max_rules": "1000",
"rgw_lc_thread_delay": "0",
root@mon01 # radosgw-admin lc list
[
{
"bucket":
":testgso:0a6e5079-ad65-4ea7-a868-b2133099e0d0.5495934.50",
"status": "COMPLETE"
}
]
root@mon01 # radosgw-admin lc get --bucket testgso
{
"prefix_map": {
"": {
"status": true,
"dm_expiration": false,
"expiration": 1,
"noncur_expiration": 0,
"mp_expiration": 1
}
},
"rule_map": [
{
"id": "111222333",
"rule": {
"id": "111222333",
"prefix": "",
"status": "Enabled",
"expiration": {
"days": "1",
"date": ""
},
"noncur_expiration": {
"days": "",
"date": ""
},
"mp_expiration": {
"days": "1",
"date": ""
},
"filter": {
"prefix": "",
"obj_tags": {}
},
"dm_expiration": false
}
}
]
}
goneill@mbp $ s3cmd -c Documents/s3cfg/testgso.cfg ls s3://testgso
DIR s3://testgso/lifecycle/
2020-03-31 17:26 12 s3://testgso/file!test.txt
2020-03-31 17:29 12 s3://testgso/file$test.txt
2020-03-31 17:29 12 s3://testgso/file&test.txt
2020-03-31 17:26 12 s3://testgso/file'test.txt
2020-03-31 17:26 12 s3://testgso/file(test.txt
2020-03-31 17:26 12 s3://testgso/file)test.txt
2020-03-31 17:29 12 s3://testgso/file*test.txt
2020-03-31 17:30 12 s3://testgso/file+test.txt
2020-03-31 17:30 12 s3://testgso/file,test.txt
2020-03-31 17:26 12 s3://testgso/file-test.txt
2020-03-31 17:30 12 s3://testgso/file:test.txt
2020-03-31 17:30 12 s3://testgso/file;test.txt
2020-03-31 17:30 12 s3://testgso/file=test.txt
2020-03-31 17:30 12 s3://testgso/file?test.txt
2020-03-31 17:06 12 s3://testgso/file@test.txt
2019-08-05 21:02 12 s3://testgso/test.txt
goneill@mbp $ s3cmd -c Documents/s3cfg/testgso.cfg getlifecycle s3://testgso
<?xml version="1.0" ?>
<LifecycleConfiguration xmlns="http://s3.amazonaws.com/doc/2006-03-01/">
<Rule>
<ID>111222333</ID>
<Prefix/>
<Status>Enabled</Status>
<Expiration>
<Days>1</Days>
</Expiration>
<AbortIncompleteMultipartUpload>
<DaysAfterInitiation>1</DaysAfterInitiation>
</AbortIncompleteMultipartUpload>
</Rule>
</LifecycleConfiguration>
### Logs from rgw01
2020-04-08 00:00:00.645 7fc55bbcc700 20 get_system_obj_state: rctx=0x7fc55bbc9bf0
obj=default.rgw.meta:root:testgso state=0x561a8bc0ac40 s->prefetch_data=0
2020-04-08 00:00:00.645 7fc55bbcc700 10 cache get: name=default.rgw.meta+root+testgso :
expiry miss
2020-04-08 00:00:00.645 7fc55bbcc700 10 cache put: name=default.rgw.meta+root+testgso
info.flags=0x16
2020-04-08 00:00:00.645 7fc55bbcc700 10 adding default.rgw.meta+root+testgso to cache LRU
end
2020-04-08 00:00:00.645 7fc55bbcc700 10 updating xattr: name=ceph.objclass.version
bl.length()=42
2020-04-08 00:00:00.645 7fc55bbcc700 20 get_system_obj_state: s->obj_tag was set empty
2020-04-08 00:00:00.645 7fc55bbcc700 20 Read xattr: user.rgw.idtag
2020-04-08 00:00:00.645 7fc55bbcc700 10 cache get: name=default.rgw.meta+root+testgso :
type miss (requested=0x13, cached=0x16)
2020-04-08 00:00:00.645 7fc55bbcc700 20 rados->read ofs=0 len=0
2020-04-08 00:00:00.646 7fc55bbcc700 20 rados_obj.operate() r=0 bl.length=181
2020-04-08 00:00:00.646 7fc55bbcc700 10 cache put: name=default.rgw.meta+root+testgso
info.flags=0x13
2020-04-08 00:00:00.646 7fc55bbcc700 10 moving default.rgw.meta+root+testgso to cache LRU
end
2020-04-08 00:00:00.646 7fc55bbcc700 10 updating xattr: name=ceph.objclass.version
bl.length()=42
2020-04-08 00:00:00.646 7fc55bbcc700 20 rgw_get_bucket_info: bucket instance:
testgso[0a6e5079-ad65-4ea7-a868-b2133099e0d0.5495934.50]
2020-04-08 00:00:00.646 7fc55bbcc700 20 reading from
default.rgw.meta:root:.bucket.meta.testgso:0a6e5079-ad65-4ea7-a868-b2133099e0d0.5495934.50
2020-04-08 00:00:00.646 7fc55bbcc700 20 get_system_obj_state: rctx=0x7fc55bbc9bf0
obj=default.rgw.meta:root:.bucket.meta.testgso:0a6e5079-ad65-4ea7-a868-b2133099e0d0.5495934.50
state=0x561a9d27d540 s->prefetch_data=0
2020-04-08 00:00:00.646 7fc55bbcc700 10 cache get:
name=default.rgw.meta+root+.bucket.meta.testgso:0a6e5079-ad65-4ea7-a868-b2133099e0d0.5495934.50
: expiry miss
2020-04-08 00:00:00.646 7fc55bbcc700 10 cache put:
name=default.rgw.meta+root+.bucket.meta.testgso:0a6e5079-ad65-4ea7-a868-b2133099e0d0.5495934.50
info.flags=0x16
2020-04-08 00:00:00.646 7fc55bbcc700 10 adding
default.rgw.meta+root+.bucket.meta.testgso:0a6e5079-ad65-4ea7-a868-b2133099e0d0.5495934.50
to cache LRU end
2020-04-08 00:00:00.646 7fc55bbcc700 10 updating xattr: name=ceph.objclass.version
bl.length()=42
2020-04-08 00:00:00.646 7fc55bbcc700 10 updating xattr: name=user.rgw.acl bl.length()=153
2020-04-08 00:00:00.646 7fc55bbcc700 10 updating xattr: name=user.rgw.lc bl.length()=130
2020-04-08 00:00:00.646 7fc55bbcc700 20 get_system_obj_state: s->obj_tag was set empty
2020-04-08 00:00:00.646 7fc55bbcc700 20 Read xattr: user.rgw.acl
2020-04-08 00:00:00.646 7fc55bbcc700 20 Read xattr: user.rgw.idtag
2020-04-08 00:00:00.646 7fc55bbcc700 20 Read xattr: user.rgw.lc
2020-04-08 00:00:00.646 7fc55bbcc700 10 cache get:
name=default.rgw.meta+root+.bucket.meta.testgso:0a6e5079-ad65-4ea7-a868-b2133099e0d0.5495934.50
: type miss (requested=0x13, cached=0x16)
2020-04-08 00:00:00.646 7fc55bbcc700 20 rados->read ofs=0 len=0
2020-04-08 00:00:00.646 7fc55bbcc700 20 rados_obj.operate() r=0 bl.length=281
2020-04-08 00:00:00.646 7fc55bbcc700 10 cache put:
name=default.rgw.meta+root+.bucket.meta.testgso:0a6e5079-ad65-4ea7-a868-b2133099e0d0.5495934.50
info.flags=0x13
2020-04-08 00:00:00.646 7fc55bbcc700 10 moving
default.rgw.meta+root+.bucket.meta.testgso:0a6e5079-ad65-4ea7-a868-b2133099e0d0.5495934.50
to cache LRU end
2020-04-08 00:00:00.646 7fc55bbcc700 10 updating xattr: name=ceph.objclass.version
bl.length()=42
2020-04-08 00:00:00.646 7fc55bbcc700 10 updating xattr: name=user.rgw.acl bl.length()=153
2020-04-08 00:00:00.646 7fc55bbcc700 10 updating xattr: name=user.rgw.lc bl.length()=130
2020-04-08 00:00:00.646 7fc55bbcc700 10 chain_cache_entry:
cache_locator=default.rgw.meta+root+testgso
2020-04-08 00:00:00.646 7fc55bbcc700 10 chain_cache_entry:
cache_locator=default.rgw.meta+root+.bucket.meta.testgso:0a6e5079-ad65-4ea7-a868-b2133099e0d0.5495934.50
2020-04-08 00:00:00.647 7fc55bbcc700 10 lifecycle: bucket_lc_process() prefix_map size=1
2020-04-08 00:00:00.647 7fc55bbcc700 20 lifecycle: bucket_lc_process(): prefix=
2020-04-08 00:00:00.647 7fc55bbcc700 10 cls_bucket_list_unordered
testgso[0a6e5079-ad65-4ea7-a868-b2133099e0d0.5495934.50] start [] num_entries 1100
2020-04-08 00:00:00.647 7fc55bbcc700 10 RGWRados::cls_bucket_list_unordered: got
file!test.txt[]
2020-04-08 00:00:00.647 7fc55bbcc700 10 RGWRados::cls_bucket_list_unordered: got
file$test.txt[]
2020-04-08 00:00:00.647 7fc55bbcc700 10 RGWRados::cls_bucket_list_unordered: got
file&test.txt[]
2020-04-08 00:00:00.647 7fc55bbcc700 10 RGWRados::cls_bucket_list_unordered: got
file'test.txt[]
2020-04-08 00:00:00.647 7fc55bbcc700 10 RGWRados::cls_bucket_list_unordered: got
file(test.txt[]
2020-04-08 00:00:00.647 7fc55bbcc700 10 RGWRados::cls_bucket_list_unordered: got
file)test.txt[]
2020-04-08 00:00:00.647 7fc55bbcc700 10 RGWRados::cls_bucket_list_unordered: got
file*test.txt[]
2020-04-08 00:00:00.647 7fc55bbcc700 10 RGWRados::cls_bucket_list_unordered: got
file+test.txt[]
2020-04-08 00:00:00.647 7fc55bbcc700 10 RGWRados::cls_bucket_list_unordered: got
file,test.txt[]
2020-04-08 00:00:00.647 7fc55bbcc700 10 RGWRados::cls_bucket_list_unordered: got
file-test.txt[]
2020-04-08 00:00:00.647 7fc55bbcc700 10 RGWRados::cls_bucket_list_unordered: got
file:test.txt[]
2020-04-08 00:00:00.647 7fc55bbcc700 10 RGWRados::cls_bucket_list_unordered: got
file;test.txt[]
2020-04-08 00:00:00.647 7fc55bbcc700 10 RGWRados::cls_bucket_list_unordered: got
file=test.txt[]
2020-04-08 00:00:00.647 7fc55bbcc700 10 RGWRados::cls_bucket_list_unordered: got
file?test.txt[]
2020-04-08 00:00:00.647 7fc55bbcc700 10 RGWRados::cls_bucket_list_unordered: got
file(a)test.txt[]
2020-04-08 00:00:00.647 7fc55bbcc700 10 RGWRados::cls_bucket_list_unordered: got
lifecycle/file.txt[]
2020-04-08 00:00:00.647 7fc55bbcc700 10 RGWRados::cls_bucket_list_unordered: got
test.txt[]
2020-04-08 00:00:00.647 7fc55bbcc700 20 lifecycle: bucket_lc_process(): key=file!test.txt
2020-04-08 00:00:00.648 7fc55bbcc700 20 obj_has_expired(): mtime=2020-03-31
13:26:07.0.481384s days=1 base_time=2020-04-08 00:00:00.000000 timediff=642833 cmp=86400
2020-04-08 00:00:00.648 7fc55bbcc700 20 check(): key=file!test.txt: is_expired=1
2020-04-08 00:00:00.648 7fc55bbcc700 20 get_obj_state: rctx=0x7fc55bbc8ff8
obj=testgso:file!test.txt state=0x561aa0c64aa0 s->prefetch_data=0
2020-04-08 00:00:00.657 7fc44f1b3700 10 manifest: total_size = 49667
2020-04-08 00:00:00.657 7fc44f1b3700 20 get_obj_state: setting s->obj_tag to
0a6e5079-ad65-4ea7-a868-b2133099e0d0.22351662.19462946
2020-04-08 00:00:00.672 7fc55bbcc700 20 get_obj_state: setting s->obj_tag to
0a6e5079-ad65-4ea7-a868-b2133099e0d0.25454121.7727201
2020-04-08 00:00:00.672 7fc55bbcc700 10 If-UnModified-Since: 2020-03-31 13:26:07.0.481384s
Last-Modified: 2020-03-31 13:26:07.000000
2020-04-08 00:00:00.672 7fc55bbcc700 20 get_obj_state: rctx=0x7fc55bbc8ff8
obj=testgso:file!test.txt state=0x561aa0c64aa0 s->prefetch_data=0
2020-04-08 00:00:00.672 7fc55bbcc700 20 prepare_atomic_modification: state is not atomic.
state=0x561aa0c64aa0
2020-04-08 00:00:00.672 7fc55bbcc700 20 reading from
default.rgw.meta:root:.bucket.meta.testgso:0a6e5079-ad65-4ea7-a868-b2133099e0d0.5495934.50
2020-04-08 00:00:00.672 7fc55bbcc700 20 get_system_obj_state: rctx=0x7fc55bbc8330
obj=default.rgw.meta:root:.bucket.meta.testgso:0a6e5079-ad65-4ea7-a868-b2133099e0d0.5495934.50
state=0x561a9d27d0c0 s->prefetch_data=0
2020-04-08 00:00:00.672 7fc55bbcc700 10 cache get:
name=default.rgw.meta+root+.bucket.meta.testgso:0a6e5079-ad65-4ea7-a868-b2133099e0d0.5495934.50
: type miss (requested=0x16, cached=0x13)
2020-04-08 00:00:00.672 7fc55bbcc700 10 cache put:
name=default.rgw.meta+root+.bucket.meta.testgso:0a6e5079-ad65-4ea7-a868-b2133099e0d0.5495934.50
info.flags=0x16
2020-04-08 00:00:00.672 7fc55bbcc700 10 moving
default.rgw.meta+root+.bucket.meta.testgso:0a6e5079-ad65-4ea7-a868-b2133099e0d0.5495934.50
to cache LRU end
2020-04-08 00:00:00.672 7fc55bbcc700 10 updating xattr: name=ceph.objclass.version
bl.length()=42
2020-04-08 00:00:00.672 7fc55bbcc700 10 updating xattr: name=user.rgw.acl bl.length()=153
2020-04-08 00:00:00.672 7fc55bbcc700 10 updating xattr: name=user.rgw.lc bl.length()=130
2020-04-08 00:00:00.672 7fc55bbcc700 20 get_system_obj_state: s->obj_tag was set empty
2020-04-08 00:00:00.672 7fc55bbcc700 10 cache get:
name=default.rgw.meta+root+.bucket.meta.testgso:0a6e5079-ad65-4ea7-a868-b2133099e0d0.5495934.50
: hit (requested=0x11, cached=0x17)
2020-04-08 00:00:00.672 7fc55bbcc700 20 bucket index object:
.dir.0a6e5079-ad65-4ea7-a868-b2133099e0d0.5495934.50
2020-04-08 00:00:00.683 7fc55bbcc700 0 ERROR: remove_expired_obj
2020-04-08 00:00:00.683 7fc55bbcc700 0 ERROR: remove_expired_obj
2020-04-08 00:00:00.683 7fc55bbcc700 20 lifecycle: ERROR: orule.process() returned
ret=-125
2020-04-08 00:00:00.683 7fc55bbcc700 20 lifecycle: bucket_lc_process(): key=file$test.txt
2020-04-08 00:00:00.683 7fc55bbcc700 20 obj_has_expired(): mtime=2020-03-31
13:29:57.0.916797s days=1 base_time=2020-04-08 00:00:00.000000 timediff=642603 cmp=86400
2020-04-08 00:00:00.683 7fc55bbcc700 20 check(): key=file$test.txt: is_expired=1
2020-04-08 00:00:00.683 7fc55bbcc700 20 get_obj_state: rctx=0x7fc55bbc8ff8
obj=testgso:file$test.txt state=0x561aa0c64aa0 s->prefetch_data=0
2020-04-08 00:00:00.684 7fc55bbcc700 10 manifest: total_size = 12
2020-04-08 00:00:00.684 7fc55bbcc700 20 get_obj_state: setting s->obj_tag to
0a6e5079-ad65-4ea7-a868-b2133099e0d0.25454121.7731015
2020-04-08 00:00:00.684 7fc55bbcc700 10 If-UnModified-Since: 2020-03-31 13:29:57.0.916797s
Last-Modified: 2020-03-31 13:29:57.000000
2020-04-08 00:00:00.684 7fc55bbcc700 20 get_obj_state: rctx=0x7fc55bbc8ff8
obj=testgso:file$test.txt state=0x561aa0c64aa0 s->prefetch_data=0
2020-04-08 00:00:00.684 7fc55bbcc700 20 prepare_atomic_modification: state is not atomic.
state=0x561aa0c64aa0
2020-04-08 00:00:00.684 7fc55bbcc700 20 reading from
default.rgw.meta:root:.bucket.meta.testgso:0a6e5079-ad65-4ea7-a868-b2133099e0d0.5495934.50
2020-04-08 00:00:00.684 7fc55bbcc700 20 get_system_obj_state: rctx=0x7fc55bbc8330
obj=default.rgw.meta:root:.bucket.meta.testgso:0a6e5079-ad65-4ea7-a868-b2133099e0d0.5495934.50
state=0x561a9d27d0c0 s->prefetch_data=0
2020-04-08 00:00:00.684 7fc55bbcc700 10 cache get:
name=default.rgw.meta+root+.bucket.meta.testgso:0a6e5079-ad65-4ea7-a868-b2133099e0d0.5495934.50
: hit (requested=0x16, cached=0x17)
2020-04-08 00:00:00.684 7fc55bbcc700 20 get_system_obj_state: s->obj_tag was set empty
2020-04-08 00:00:00.684 7fc55bbcc700 10 cache get:
name=default.rgw.meta+root+.bucket.meta.testgso:0a6e5079-ad65-4ea7-a868-b2133099e0d0.5495934.50
: hit (requested=0x11, cached=0x17)
2020-04-08 00:00:00.684 7fc55bbcc700 20 bucket index object:
.dir.0a6e5079-ad65-4ea7-a868-b2133099e0d0.5495934.50
2020-04-08 00:00:00.711 7fc55bbcc700 0 ERROR: remove_expired_obj
2020-04-08 00:00:00.711 7fc55bbcc700 0 ERROR: remove_expired_obj
2020-04-08 00:00:00.711 7fc55bbcc700 20 lifecycle: ERROR: orule.process() returned
ret=-125
1501
days inactive
1501
days old
0 comments
1 participants
participants (1)
-
oneill.gs＠gmail.com