Actions
Bug #12659
closedCan't delete cache pool
Status:
Closed
Priority:
High
Assignee:
-
Category:
Tiering
Target version:
-
% Done:
0%
Source:
Community (user)
Tags:
Backport:
Regression:
No
Severity:
3 - minor
Reviewed:
Affected Versions:
ceph-qa-suite:
Component(RADOS):
Pull request ID:
Crash signature (v1):
Crash signature (v2):
Description
Hi,
this is kind of a follow-up from issue #10138 where we encountered some strange issues with cache tiers.
One of our pools affected by these issues is still up and running and we want to get rid of the cache tier.
However, we can't delete it because it seems to be in a really weird state.
Situation:
$ ceph -v
ceph version 0.94.2 (5fb85614ca8f354284c713a2f9c610860720bbf3)
$ ceph osd pool ls detail
pool 5 'data' replicated size 3 min_size 2 crush_ruleset 3 object_hash rjenkins pg_num 1024 pgp_num 1024 last_change 25444 lfor 901 flags hashpspool tiers 7 read_tier 7 write_tier 7 min_read_recency_for_promote 1 stripe_width 0
removed_snaps [1~b0,be~4,c3~a2,166~130,297~4,29c~c,2a9~10,2ba~93,34e~4a,39b~1,3af~44,408~1,41e~1,42f~1,445~1,45b~1,45d~1,45f~1,461~1,463~1,465~2]
pool 7 'ssd_cache' replicated size 3 min_size 2 crush_ruleset 4 object_hash rjenkins pg_num 64 pgp_num 64 last_change 27177 flags hashpspool,incomplete_clones tier_of 5 cache_mode forward hit_set bloom{false_positive_probability: 0.05, target_size: 0, seed: 0} 3600s x1 min_read_recency_for_promote 1 stripe_width 0
data is the actual pool, ssd_cache the cache. As you can see, we aren't really using it.
We are trying to delete it like this:
$ ceph osd tier cache-mode ssd_cache forward
set cache-mode for pool 'ssd_cache' to forward
$ rados -p ssd_cache cache-flush-evict-all
rbd_data.576562ae8944a.000000000000028b
failed to evict /rbd_data.576562ae8944a.000000000000028b: (16) Device or resource busy
rbd_header.1cc57b238e1f29
failed to evict /rbd_header.1cc57b238e1f29: (16) Device or resource busy
rbd_header.2019cd238e1f29
... etc
All these objects that it's complaining about are also visible in the pool:
$ rados -p ssd_cache ls rbd_data.576562ae8944a.000000000000028b rbd_header.1cc57b238e1f29 rbd_header.2019cd238e1f29 ...
Now, since some of these RBD images in question don't contain any valuable data, we just tried to delete one of the objects in the cache pool to check what happens, but deleting doesn't really seem to work on this cache pool:
$ rados -p ssd_cache rm rbd_header.784aca238e1f29 $ rados -p ssd_cache ls |grep rbd_header.784aca238e1f29 rbd_header.784aca238e1f29 # it's still there? huh? $ rados -p ssd_cache rm rbd_header.784aca238e1f29 error removing ssd_cache>rbd_header.784aca238e1f29: (2) No such file or directory # or isn't it?
I'm just gonna assume that this weird behavior is somehow expected since this is a cache pool and we didn't delete the object from the actual pool.
However, the object we just deleted still shows up as one of the objects that it can't evict:
$ rados -p ssd_cache cache-flush-evict-all 2>&1 |grep 784aca238e1f29
rbd_header.784aca238e1f29
Our current best solution is to migrate that broken pool to a new pool to fix this, but that would take quite some time.
Maybe someone has a better idea?
Paul
Updated by Sage Weil over 8 years ago
- Status changed from New to Need More Info
Have you resolved this? It sounds like there was ongoing client io to those objects that preventing hte flush + evict...
Updated by Paul Emmerich over 8 years ago
One of the objects that can't be evicted is the RBD header of a VM disk - a VM that hasn't been used in months: it's not even running. There are also no snapshots or clones, so there should be no IO at all on that object
We will just move these objects to a different pool to fix this.
Updated by Sam Yaple about 8 years ago
Just ran into this in a fresh cluster. Same behavior described above. I had a protected snapshot on the rbd in question. Once I unprotected and removed the snapshot the cache evict worked like it should.
Updated by Josh Durgin about 8 years ago
If anyone runs into this again, could you gather 'debug osd = 20' logs from the osd storing the troublesome rbd_header object while trying to evict it?
It's unclear if this was a rogue watcher keeping its watch on the rbd header, or some other reason for the osd to return EBUSY.
Updated by Sam Yaple about 8 years ago
@Josh Jones, this behavior is easily duplicated.
prereq- setup pool and cachetier in writeback
1. create rbd
2. create snapshot
3. protect snapshot (not sure this is needed)
4. modify rbd (in my case I issued fstrim/blkdiscard when dropped blocks that the snapshot was using, that may be key)
5. cache-flush-evict-all and see "(16) Device or resource busy"
When digging into it you'll actually find another equally confusing error message "(2) no such file or directory" in one of the logs.
Updated by Christian Theune over 7 years ago
I'm also being bitten by this. I shut down all VMs and supposedly all clients that talk to our ceph cluster, but I still get that.
(Additionally I'm fighting issues with OSD stability as the DNS is currently not around. I've had OSDs involved with the cache tier segfault multiple times now. This is on hammer 0.94.7.)
Here's log output that I think may be helpful:
2016-11-10 12:26:11.739501 7f9ce35f4700 15 osd.7 399987 enqueue_op 0x7f9c7469c600 prio 63 cost 0 latency 0.000171 osd_op(client.33207837.0:5 rbd_data.134c93a238e1f29.0000000000000073 [cache-flush] 621.ee218400 ack+read+ignore_cache+ignore_overlay+known_if_redirected e399987) v5 2016-11-10 12:26:11.739542 7f9ca13f8700 10 osd.7 399987 dequeue_op 0x7f9c7469c600 prio 63 cost 0 latency 0.000213 osd_op(client.33207837.0:5 rbd_data.134c93a238e1f29.0000000000000073 [cache-flush] 621.ee218400 ack+read+ignore_cache+ignore_overlay+known_if_redirected e399987) v5 pg pg[621.0( v 399902'3851 (398592'800,399902'3851] local-les=399968 n=32 ec=398464 les/c 399968/399968 399967/399967/399942) [7,12] r=0 lpr=399967 crt=399902'3849 lcod 0'0 mlcod 0'0 active+clean snaptrimq=[6d57~344d]] 2016-11-10 12:26:11.739575 7f9ca13f8700 20 osd.7 pg_epoch: 399987 pg[621.0( v 399902'3851 (398592'800,399902'3851] local-les=399968 n=32 ec=398464 les/c 399968/399968 399967/399967/399942) [7,12] r=0 lpr=399967 crt=399902'3849 lcod 0'0 mlcod 0'0 active+clean snaptrimq=[6d57~344d]] op_has_sufficient_caps pool=621 (rbd.cache ) owner=0 need_read_cap=0 need_write_cap=0 need_class_read_cap=0 need_class_write_cap=0 -> yes 2016-11-10 12:26:11.739593 7f9ca13f8700 10 osd.7 pg_epoch: 399987 pg[621.0( v 399902'3851 (398592'800,399902'3851] local-les=399968 n=32 ec=398464 les/c 399968/399968 399967/399967/399942) [7,12] r=0 lpr=399967 crt=399902'3849 lcod 0'0 mlcod 0'0 active+clean snaptrimq=[6d57~344d]] handle_message: 0x7f9c7469c600 2016-11-10 12:26:11.739606 7f9ca13f8700 10 osd.7 pg_epoch: 399987 pg[621.0( v 399902'3851 (398592'800,399902'3851] local-les=399968 n=32 ec=398464 les/c 399968/399968 399967/399967/399942) [7,12] r=0 lpr=399967 crt=399902'3849 lcod 0'0 mlcod 0'0 active+clean snaptrimq=[6d57~344d]] do_op osd_op(client.33207837.0:5 rbd_data.134c93a238e1f29.0000000000000073 [cache-flush] 621.ee218400 ack+read+ignore_cache+ignore_overlay+known_if_redirected e399987) v5 may_cache -> write-ordered flags ack+read+ig nore_cache+ignore_overlay+known_if_redirected 2016-11-10 12:26:11.739633 7f9ca13f8700 10 osd.7 pg_epoch: 399987 pg[621.0( v 399902'3851 (398592'800,399902'3851] local-les=399968 n=32 ec=398464 les/c 399968/399968 399967/399967/399942) [7,12] r=0 lpr=399967 crt=399902'3849 lcod 0'0 mlcod 0'0 active+clean snaptrimq=[6d57~344d]] get_object_context: obc NOT found in cache: 621/ee218400/rbd_data.134c93a238e1f29.0000000000000073/head 2016-11-10 12:26:11.739901 7f9ca13f8700 10 osd.7 pg_epoch: 399987 pg[621.0( v 399902'3851 (398592'800,399902'3851] local-les=399968 n=32 ec=398464 les/c 399968/399968 399967/399967/399942) [7,12] r=0 lpr=399967 crt=399902'3849 lcod 0'0 mlcod 0'0 active+clean snaptrimq=[6d57~344d]] populate_obc_watchers 621/ee218400/rbd_data.134c93a238e1f29.0000000000000073/head 2016-11-10 12:26:11.739921 7f9ca13f8700 20 osd.7 pg_epoch: 399987 pg[621.0( v 399902'3851 (398592'800,399902'3851] local-les=399968 n=32 ec=398464 les/c 399968/399968 399967/399967/399942) [7,12] r=0 lpr=399967 crt=399902'3849 lcod 0'0 mlcod 0'0 active+clean snaptrimq=[6d57~344d]] ReplicatedPG::check_blacklisted_obc_watchers for obc 621/ee218400/rbd_data.134c93a238e1f29.0000000000000073/head 2016-11-10 12:26:11.739932 7f9ca13f8700 10 osd.7 pg_epoch: 399987 pg[621.0( v 399902'3851 (398592'800,399902'3851] local-les=399968 n=32 ec=398464 les/c 399968/399968 399967/399967/399942) [7,12] r=0 lpr=399967 crt=399902'3849 lcod 0'0 mlcod 0'0 active+clean snaptrimq=[6d57~344d]] get_object_context: creating obc from disk: 0x7f9c9f5a7300 2016-11-10 12:26:11.739946 7f9ca13f8700 10 osd.7 pg_epoch: 399987 pg[621.0( v 399902'3851 (398592'800,399902'3851] local-les=399968 n=32 ec=398464 les/c 399968/399968 399967/399967/399942) [7,12] r=0 lpr=399967 crt=399902'3849 lcod 0'0 mlcod 0'0 active+clean snaptrimq=[6d57~344d]] get_object_context: 0x7f9c9f5a7300 621/ee218400/rbd_data.134c93a238e1f29.0000000000000073/head rwstate(none n=0 w=0) oi: 621/ee218400/rbd_data.134c93a238e1f29.0000000000000073/head(399902'3518 osd.7.0:8558968 wrlock _by=unknown.0.0:0 s 4194304 uv 7506162) ssc: 0x7f9c6a83c800 snapset: a048=[a048,9dbb,9a74]:[9a74,9dbb,a048]+head 2016-11-10 12:26:11.739963 7f9ca13f8700 10 osd.7 pg_epoch: 399987 pg[621.0( v 399902'3851 (398592'800,399902'3851] local-les=399968 n=32 ec=398464 les/c 399968/399968 399967/399967/399942) [7,12] r=0 lpr=399967 crt=399902'3849 lcod 0'0 mlcod 0'0 active+clean snaptrimq=[6d57~344d]] find_object_context 621/ee218400/rbd_data.134c93a23 8e1f29.0000000000000073/head @head oi=621/ee218400/rbd_data.134c93a238e1f29.0000000000000073/head(399902'3518 osd.7.0:8558968 wrlock_by=unknown.0.0:0 s 4194304 uv 7506162) 2016-11-10 12:26:11.739981 7f9ca13f8700 10 osd.7 pg_epoch: 399987 pg[621.0( v 399902'3851 (398592'800,399902'3851] local-les=399968 n=32 ec=398464 les/c 399968/399968 399967/399967/399942) [7,12] r=0 lpr=399967 crt=399902'3849 lcod 0'0 mlcod 0'0 active+clean snaptrimq=[6d57~344d]] agent_choose_mode flush_mode: idle evict_mode: idle num_objects: 32 num_bytes: 64905613 num_objects_dirty: 12 num_objects_omap: 0 num_dirty: 12 num_user_objects: 31 num_user_bytes: 64905216 pool.info.target_max_bytes: 252687242581 pool.info.target_max_objects: 1000000 2016-11-10 12:26:11.739996 7f9ca13f8700 20 osd.7 pg_epoch: 399987 pg[621.0( v 399902'3851 (398592'800,399902'3851] local-les=399968 n=32 ec=398464 les/c 399968/399968 399967/399967/399942) [7,12] r=0 lpr=399967 crt=399902'3849 lcod 0'0 mlcod 0'0 active+clean snaptrimq=[6d57~344d]] agent_choose_mode dirty 0.050907 full 0.131512 2016-11-10 12:26:11.740043 7f9ca13f8700 10 osd.7 pg_epoch: 399987 pg[621.0( v 399902'3851 (398592'800,399902'3851] local-les=399968 n=32 ec=398464 les/c 399968/399968 399967/399967/399942) [7,12] r=0 lpr=399967 crt=399902'3849 lcod 0'0 mlcod 0'0 active+clean snaptrimq=[6d57~344d]] execute_ctx 0x7f9c9f4f8e00 2016-11-10 12:26:11.740063 7f9ca13f8700 10 osd.7 pg_epoch: 399987 pg[621.0( v 399902'3851 (398592'800,399902'3851] local-les=399968 n=32 ec=398464 les/c 399968/399968 399967/399967/399942) [7,12] r=0 lpr=399967 crt=399902'3849 lcod 0'0 mlcod 0'0 active+clean snaptrimq=[6d57~344d]] do_op 621/ee218400/rbd_data.134c93a238e1f29.0000000000000073/head [cache-flush] ov 399902'3518 av 399987'3852 snapc 0=[] snapset a048=[a048,9dbb,9a74]:[9a74,9dbb,a048]+head 2016-11-10 12:26:11.740080 7f9ca13f8700 10 osd.7 pg_epoch: 399987 pg[621.0( v 399902'3851 (398592'800,399902'3851] local-les=399968 n=32 ec=398464 les/c 399968/399968 399967/399967/399942) [7,12] r=0 lpr=399967 crt=399902'3849 lcod 0'0 mlcod 0'0 active+clean snaptrimq=[6d57~344d]] do_osd_op 621/ee218400/rbd_data.134c93a238e1f29.0000000000000073/head [cache-flush] 2016-11-10 12:26:11.740092 7f9ca13f8700 10 osd.7 pg_epoch: 399987 pg[621.0( v 399902'3851 (398592'800,399902'3851] local-les=399968 n=32 ec=398464 les/c 399968/399968 399967/399967/399942) [7,12] r=0 lpr=399967 crt=399902'3849 lcod 0'0 mlcod 0'0 active+clean snaptrimq=[6d57~344d]] do_osd_op cache-flush 2016-11-10 12:26:11.740107 7f9ca13f8700 15 osd.7 pg_epoch: 399987 pg[621.0( v 399902'3851 (398592'800,399902'3851] local-les=399968 n=32 ec=398464 les/c 399968/399968 399967/399967/399942) [7,12] r=0 lpr=399967 crt=399902'3849 lcod 0'0 mlcod 0'0 active+clean snaptrimq=[6d57~344d]] do_osd_op_effects client.33207837 con 0x7f9c9d851b00 2016-11-10 12:26:11.740122 7f9ca13f8700 15 osd.7 pg_epoch: 399987 pg[621.0( v 399902'3851 (398592'800,399902'3851] local-les=399968 n=32 ec=398464 les/c 399968/399968 399967/399967/399942) [7,12] r=0 lpr=399967 crt=399902'3849 lcod 0'0 mlcod 0'0 active+clean snaptrimq=[6d57~344d]] log_op_stats osd_op(client.33207837.0:5 rbd_data.134c93a238e1f29.0000000000000073 [cache-flush] 621.ee218400 ack+read+ignore_cache+ignore_overlay+known_if_redirected e399987) v5 inb 0 outb 0 rlat 0.000000 lat 0.000792 2016-11-10 12:26:11.740142 7f9ca13f8700 15 osd.7 pg_epoch: 399987 pg[621.0( v 399902'3851 (398592'800,399902'3851] local-les=399968 n=32 ec=398464 les/c 399968/399968 399967/399967/399942) [7,12] r=0 lpr=399967 crt=399902'3849 lcod 0'0 mlcod 0'0 active+clean snaptrimq=[6d57~344d]] publish_stats_to_osd 399968: no change since 2016-11-10 12:26:11.740170 7f9ca13f8700 10 osd.7 399987 dequeue_op 0x7f9c7469c600 finish 2016-11-10 12:26:11.740696 7f9ce35f4700 20 osd.7 399987 should_share_map client.33207837 172.20.4.51:0/2159014009 399987 2016-11-10 12:26:11.740722 7f9ce35f4700 15 osd.7 399987 enqueue_op 0x7f9c7469c700 prio 63 cost 0 latency 0.000141 osd_op(client.33207837.0:6 rbd_data.134c93a238e1f29.0000000000000073 [cache-evict] 621.ee218400 ack+read+ignore_cache+skiprwlocks+ignore_overlay+known_if_redirected e399987) v5 2016-11-10 12:26:11.740822 7f9c9cbfe700 10 osd.7 399987 dequeue_op 0x7f9c7469c700 prio 63 cost 0 latency 0.000241 osd_op(client.33207837.0:6 rbd_data.134c93a238e1f29.0000000000000073 [cache-evict] 621.ee218400 ack+read+ignore_cache+skiprwlocks+ignore_overlay+known_if_redirected e399987) v5 pg pg[621.0( v 399902'3851 (398592'800,399902'3851] local-les=399968 n=32 ec=398464 les/c 399968/399968 399967/399967/399942) [7,12] r=0 lpr=399967 crt=399902'3849 lcod 0'0 mlcod 0'0 active+clean snaptrimq=[6d57~344d]] 2016-11-10 12:26:11.740869 7f9c9cbfe700 20 osd.7 pg_epoch: 399987 pg[621.0( v 399902'3851 (398592'800,399902'3851] local-les=399968 n=32 ec=398464 les/c 399968/399968 399967/399967/399942) [7,12] r=0 lpr=399967 crt=399902'3849 lcod 0'0 mlcod 0'0 active+clean snaptrimq=[6d57~344d]] op_has_sufficient_caps pool=621 (rbd.cache ) owner=0 need_read_cap=0 need_write_cap=0 need_class_read_cap=0 need_class_write_cap=0 -> yes 2016-11-10 12:26:11.740888 7f9c9cbfe700 10 osd.7 pg_epoch: 399987 pg[621.0( v 399902'3851 (398592'800,399902'3851] local-les=399968 n=32 ec=398464 les/c 399968/399968 399967/399967/399942) [7,12] r=0 lpr=399967 crt=399902'3849 lcod 0'0 mlcod 0'0 active+clean snaptrimq=[6d57~344d]] handle_message: 0x7f9c7469c700 2016-11-10 12:26:11.740901 7f9c9cbfe700 10 osd.7 pg_epoch: 399987 pg[621.0( v 399902'3851 (398592'800,399902'3851] local-les=399968 n=32 ec=398464 les/c 399968/399968 399967/399967/399942) [7,12] r=0 lpr=399967 crt=399902'3849 lcod 0'0 mlcod 0'0 active+clean snaptrimq=[6d57~344d]] do_op osd_op(client.33207837.0:6 rbd_data.134c93a238e1f29.0000000000000073 [cache-evict] 621.ee218400 ack+read+ignore_cache+skiprwlocks+ignore_overlay+known_if_redirected e399987) v5 may_cache -> write-ordered flags ack+read+ignore_cache+skiprwlocks+ignore_overlay+known_if_redirected 2016-11-10 12:26:11.740926 7f9c9cbfe700 10 osd.7 pg_epoch: 399987 pg[621.0( v 399902'3851 (398592'800,399902'3851] local-les=399968 n=32 ec=398464 les/c 399968/399968 399967/399967/399942) [7,12] r=0 lpr=399967 crt=399902'3849 lcod 0'0 mlcod 0'0 active+clean snaptrimq=[6d57~344d]] get_object_context: found obc in cache: 0x7f9c9f5a7300 2016-11-10 12:26:11.740940 7f9c9cbfe700 10 osd.7 pg_epoch: 399987 pg[621.0( v 399902'3851 (398592'800,399902'3851] local-les=399968 n=32 ec=398464 les/c 399968/399968 399967/399967/399942) [7,12] r=0 lpr=399967 crt=399902'3849 lcod 0'0 mlcod 0'0 active+clean snaptrimq=[6d57~344d]] get_object_context: 0x7f9c9f5a7300 621/ee218400/rbd_data.134c93a238e1f29.0000000000000073/head rwstate(none n=0 w=0) oi: 621/ee218400/rbd_data.134c93a238e1f29.0000000000000073/head(399902'3518 osd.7.0:8558968 wrlock_by=unknown.0.0:0 s 4194304 uv 7506162) ssc: 0x7f9c6a83c800 snapset: a048=[a048,9dbb,9a74]:[9a74,9dbb,a048]+head 2016-11-10 12:26:11.740957 7f9c9cbfe700 10 osd.7 pg_epoch: 399987 pg[621.0( v 399902'3851 (398592'800,399902'3851] local-les=399968 n=32 ec=398464 les/c 399968/399968 399967/399967/399942) [7,12] r=0 lpr=399967 crt=399902'3849 lcod 0'0 mlcod 0'0 active+clean snaptrimq=[6d57~344d]] find_object_context 621/ee218400/rbd_data.134c93a238e1f29.0000000000000073/head @head oi=621/ee218400/rbd_data.134c93a238e1f29.0000000000000073/head(399902'3518 osd.7.0:8558968 wrlock_by=unknown.0.0:0 s 4194304 uv 7506162) 2016-11-10 12:26:11.740980 7f9c9cbfe700 10 osd.7 pg_epoch: 399987 pg[621.0( v 399902'3851 (398592'800,399902'3851] local-les=399968 n=32 ec=398464 les/c 399968/399968 399967/399967/399942) [7,12] r=0 lpr=399967 crt=399902'3849 lcod 0'0 mlcod 0'0 active+clean snaptrimq=[6d57~344d]] agent_choose_mode flush_mode: idle evict_mode: idle num_objects: 32 num_bytes: 64905613 num_objects_dirty: 12 num_objects_omap: 0 num_dirty: 12 num_user_objects: 31 num_user_bytes: 64905216 pool.info.target_max_bytes: 252687242581 pool.info.target_max_objects: 1000000 2016-11-10 12:26:11.741012 7f9c9cbfe700 20 osd.7 pg_epoch: 399987 pg[621.0( v 399902'3851 (398592'800,399902'3851] local-les=399968 n=32 ec=398464 les/c 399968/399968 399967/399967/399942) [7,12] r=0 lpr=399967 crt=399902'3849 lcod 0'0 mlcod 0'0 active+clean snaptrimq=[6d57~344d]] agent_choose_mode dirty 0.050907 full 0.131512 2016-11-10 12:26:11.741034 7f9c9cbfe700 20 osd.7 pg_epoch: 399987 pg[621.0( v 399902'3851 (398592'800,399902'3851] local-les=399968 n=32 ec=398464 les/c 399968/399968 399967/399967/399942) [7,12] r=0 lpr=399967 crt=399902'3849 lcod 0'0 mlcod 0'0 active+clean snaptrimq=[6d57~344d]] do_op: skipping rw locks 2016-11-10 12:26:11.741057 7f9c9cbfe700 10 osd.7 pg_epoch: 399987 pg[621.0( v 399902'3851 (398592'800,399902'3851] local-les=399968 n=32 ec=398464 les/c 399968/399968 399967/399967/399942) [7,12] r=0 lpr=399967 crt=399902'3849 lcod 0'0 mlcod 0'0 active+clean snaptrimq=[6d57~344d]] execute_ctx 0x7f9c9f4f8200 2016-11-10 12:26:11.741071 7f9c9cbfe700 10 osd.7 pg_epoch: 399987 pg[621.0( v 399902'3851 (398592'800,399902'3851] local-les=399968 n=32 ec=398464 les/c 399968/399968 399967/399967/399942) [7,12] r=0 lpr=399967 crt=399902'3849 lcod 0'0 mlcod 0'0 active+clean snaptrimq=[6d57~344d]] do_op 621/ee218400/rbd_data.134c93a238e1f29.0000000000000073/head [cache-evict] ov 399902'3518 av 399987'3852 snapc 0=[] snapset a048=[a048,9dbb,9a74]:[9a74,9dbb,a048]+head 2016-11-10 12:26:11.741088 7f9c9cbfe700 10 osd.7 pg_epoch: 399987 pg[621.0( v 399902'3851 (398592'800,399902'3851] local-les=399968 n=32 ec=398464 les/c 399968/399968 399967/399967/399942) [7,12] r=0 lpr=399967 crt=399902'3849 lcod 0'0 mlcod 0'0 active+clean snaptrimq=[6d57~344d]] do_osd_op 621/ee218400/rbd_data.134c93a238e1f29.0000000000000073/head [cache-evict] 2016-11-10 12:26:11.741100 7f9c9cbfe700 10 osd.7 pg_epoch: 399987 pg[621.0( v 399902'3851 (398592'800,399902'3851] local-les=399968 n=32 ec=398464 les/c 399968/399968 399967/399967/399942) [7,12] r=0 lpr=399967 crt=399902'3849 lcod 0'0 mlcod 0'0 active+clean snaptrimq=[6d57~344d]] do_osd_op cache-evict 2016-11-10 12:26:11.741110 7f9c9cbfe700 20 osd.7 pg_epoch: 399987 pg[621.0( v 399902'3851 (398592'800,399902'3851] local-les=399968 n=32 ec=398464 les/c 399968/399968 399967/399967/399942) [7,12] r=0 lpr=399967 crt=399902'3849 lcod 0'0 mlcod 0'0 active+clean snaptrimq=[6d57~344d]] _verify_no_head_clones verifying clones are absent a048=[a048,9dbb,9a74]:[9a74,9dbb,a048]+head 2016-11-10 12:26:11.741124 7f9c9cbfe700 10 osd.7 pg_epoch: 399987 pg[621.0( v 399902'3851 (398592'800,399902'3851] local-les=399968 n=32 ec=398464 les/c 399968/399968 399967/399967/399942) [7,12] r=0 lpr=399967 crt=399902'3849 lcod 0'0 mlcod 0'0 active+clean snaptrimq=[6d57~344d]] get_object_context: obc NOT found in cache: 621/ee218400/rbd_data.134c93a238e1f29.0000000000000073/9a74 2016-11-10 12:26:11.741172 7f9c9cbfe700 10 osd.7 pg_epoch: 399987 pg[621.0( v 399902'3851 (398592'800,399902'3851] local-les=399968 n=32 ec=398464 les/c 399968/399968 399967/399967/399942) [7,12] r=0 lpr=399967 crt=399902'3849 lcod 0'0 mlcod 0'0 active+clean snaptrimq=[6d57~344d]] get_object_context: no obc for soid 621/ee218400/rbd_data.134c93a238e1f29.0000000000000073/9a74 and !can_create 2016-11-10 12:26:11.741191 7f9c9cbfe700 10 osd.7 pg_epoch: 399987 pg[621.0( v 399902'3851 (398592'800,399902'3851] local-les=399968 n=32 ec=398464 les/c 399968/399968 399967/399967/399942) [7,12] r=0 lpr=399967 crt=399902'3849 lcod 0'0 mlcod 0'0 active+clean snaptrimq=[6d57~344d]] get_object_context: obc NOT found in cache: 621/ee218400/rbd_data.134c93a238e1f29.0000000000000073/9dbb 2016-11-10 12:26:11.741229 7f9c9cbfe700 10 osd.7 pg_epoch: 399987 pg[621.0( v 399902'3851 (398592'800,399902'3851] local-les=399968 n=32 ec=398464 les/c 399968/399968 399967/399967/399942) [7,12] r=0 lpr=399967 crt=399902'3849 lcod 0'0 mlcod 0'0 active+clean snaptrimq=[6d57~344d]] get_object_context: no obc for soid 621/ee218400/rbd_data.134c93a238e1f29.0000000000000073/9dbb and !can_create 2016-11-10 12:26:11.741247 7f9c9cbfe700 10 osd.7 pg_epoch: 399987 pg[621.0( v 399902'3851 (398592'800,399902'3851] local-les=399968 n=32 ec=398464 les/c 399968/399968 399967/399967/399942) [7,12] r=0 lpr=399967 crt=399902'3849 lcod 0'0 mlcod 0'0 active+clean snaptrimq=[6d57~344d]] get_object_context: obc NOT found in cache: 621/ee218400/rbd_data.134c93a238e1f29.0000000000000073/a048 2016-11-10 12:26:11.741500 7f9c9cbfe700 10 osd.7 pg_epoch: 399987 pg[621.0( v 399902'3851 (398592'800,399902'3851] local-les=399968 n=32 ec=398464 les/c 399968/399968 399967/399967/399942) [7,12] r=0 lpr=399967 crt=399902'3849 lcod 0'0 mlcod 0'0 active+clean snaptrimq=[6d57~344d]] populate_obc_watchers 621/ee218400/rbd_data.134c93a238e1f29.0000000000000073/a048 2016-11-10 12:26:11.741522 7f9c9cbfe700 20 osd.7 pg_epoch: 399987 pg[621.0( v 399902'3851 (398592'800,399902'3851] local-les=399968 n=32 ec=398464 les/c 399968/399968 399967/399967/399942) [7,12] r=0 lpr=399967 crt=399902'3849 lcod 0'0 mlcod 0'0 active+clean snaptrimq=[6d57~344d]] ReplicatedPG::check_blacklisted_obc_watchers for obc 621/ee218400/rbd_data.134c93a238e1f29.0000000000000073/a048 2016-11-10 12:26:11.741536 7f9c9cbfe700 10 osd.7 pg_epoch: 399987 pg[621.0( v 399902'3851 (398592'800,399902'3851] local-les=399968 n=32 ec=398464 les/c 399968/399968 399967/399967/399942) [7,12] r=0 lpr=399967 crt=399902'3849 lcod 0'0 mlcod 0'0 active+clean snaptrimq=[6d57~344d]] get_object_context: creating obc from disk: 0x7f9c9a177c00 2016-11-10 12:26:11.741549 7f9c9cbfe700 10 osd.7 pg_epoch: 399987 pg[621.0( v 399902'3851 (398592'800,399902'3851] local-les=399968 n=32 ec=398464 les/c 399968/399968 399967/399967/399942) [7,12] r=0 lpr=399967 crt=399902'3849 lcod 0'0 mlcod 0'0 active+clean snaptrimq=[6d57~344d]] get_object_context: 0x7f9c9a177c00 621/ee218400/rbd_data.134c93a238e1f29.0000000000000073/a048 rwstate(none n=0 w=0) oi: 621/ee218400/rbd_data.134c93a238e1f29.0000000000000073/a048(399408'2739 osd.7.0:7977328 [a048] data_digest s 4194304 uv 7504291 dd a2b1df4a) ssc: 0x7f9c6a83c800 snapset: a048=[a048,9dbb,9a74]:[9a74,9dbb,a048]+head 2016-11-10 12:26:11.741567 7f9c9cbfe700 10 osd.7 pg_epoch: 399987 pg[621.0( v 399902'3851 (398592'800,399902'3851] local-les=399968 n=32 ec=398464 les/c 399968/399968 399967/399967/399942) [7,12] r=0 lpr=399967 crt=399902'3849 lcod 0'0 mlcod 0'0 active+clean snaptrimq=[6d57~344d]] _verify_no_head_clones cannot evict head before clone 621/ee218400/rbd_data.134c93a238e1f29.0000000000000073/a048 2016-11-10 12:26:11.741605 7f9c9cbfe700 10 osd.7 399987 dequeue_op 0x7f9c7469c700 finish
Updated by Christian Theune over 7 years ago
The specific check that triggers is the one from here:
http://tracker.ceph.com/issues/8003
I'm still trying to find a workaround, as my (development) cluster is currently screwed.
Flattening and purging all snapshots did not help. In `rados ls` I do not see object names that appear to be snapshot-related, but maybe this doesn't show on this level anyways:
... rbd_data.13621c074b0dc51.000000000000018a rbd_data.13527a73d1b58ba.000000000000057e rbd_data.135f7df2eb141f2.000000000002a34d rbd_data.13527a73d1b58ba.0000000000000949 rbd_data.1b3d5132eb141f2.0000000000005d93 rbd_data.135f7df2eb141f2.000000000000f4fb rbd_data.134c93a238e1f29.0000000000000016 rbd_data.135f7df2eb141f2.000000000002902a ...
Updated by Christian Theune over 7 years ago
Ah, and I misread. It's not about snapshots, it's about clones. Right. So I do have clones, but all of them have been flattened. I think.
/me searches for more ways to detach clones.
Updated by Christian Theune over 7 years ago
Ok, this is weird. I deleted all snapshots. This means effectively there can't be any clones any longer as I can only make clones off of snapshots. Grr. Running out of ideas for workarounds.
Updated by Christian Theune over 7 years ago
As my development environment is down anyway, I'm now trying to:
- rename all images (mv foo foo.alt)
- copy them back to their original location (cp foo.alt foo) and remove the original
That should get rid of any structures mentioning clones ... I think.
I'll be back in a minute or so.
Updated by Christian Theune over 7 years ago
That didn't work. At. All.
I could not delete the alt images (OSDs kept crashing). I finally decided to just rip out the unclean tiering.
Interestingly it seems that even though the cache pool was in forward mode - which as I understand the documentation is intended to stop any new promitions and also turn to write-through - that all the data ended up in the cache pool. The underlying pool did not reflect any of my changes. Even the locks from the VMs that were cleanly shut down still existed.
The data is a bit garbled now, but we've got backups.
Interestingly: even VMs that were not involved with any cloning are showing symptoms of corruption, even though I had evicted the objects that I could from the pool after turning it to forwarding - I think. It was a bit chaotic at that point.
I still have a second dev cluster that I would like to remove the cache tier from - if you need more analysis or stuff then I can produce that from there.
Updated by Sage Weil about 7 years ago
- Priority changed from Normal to High
Just found this bug. Is this still causing problems?
Updated by Greg Farnum almost 7 years ago
- Project changed from Ceph to RADOS
- Category set to Tiering
- Status changed from Need More Info to Closed
Closing due to lack of updates and various changes in cache pools since .94.
Actions