Ceph » RADOS

We have had this problem for a long time, one reason was resolved in #37439. But it still persists in some cases, and I did not dig deep for remaining causes yet.

Can you provide ceph pg $id dump for the pg that is degraded? It will probably say (at the bottom) that it did query the OSD where we expect the data to be, but did not succeed (the might_have_unfound part in pg dump).

What also works to recover is revert the change to the placement, wait for peering, and then restore it. Data will be found, and then only be "misplaced" again.

Thanks a lot for this info. There have been a few more scenarios discussed on the users-list, all involving changes to the crush map (adding OSDs, re-weighting, etc) while OSDs were down or restarting at the same time. In all such cases, objects of EC pools go missing.

My description indeed matches scenario 1 in #37439 and I'm wondering why it still shows up when this particular situation was fixed.

Can you provide ceph pg $id dump for the pg that is degraded? It will probably say (at the bottom)
that it did query the OSD where we expect the data to be, but did not succeed (the might_have_unfound part in pg dump).

I will. Could you please let me know what commands you have in mind here:

What also works to recover is revert the change to the placement, wait for peering, and then restore it. Data will be found, and then only be "misplaced" again.

I would like to try this as a recovery method.

Ok, that's the same state I see our PGs in when they become degraded due to remappings (might_have_unfound: already_probed).

The command to restore the peering depends on what caused the remap. E.g. if you took an OSD out, you'd put it in again, wait for rediscovery, and take it out. It seems that the peering/pglog discovery only finds the data if the crush state would place the data exactly where it was before.

The already_probed state seems to hint that somehow the PG states did not match, so the originating PG wasn't considered as source (even though it is the (only) suitable shard source). Ceph knew to query the correct OSD (74), so the rediscovery method is not totally broken.

In your log this only is a problem since "new" OSDs are not the source of the movement, but the "old" OSD is (hence the data degrade).

So I guess we have to stare at the code and see why the probing doesn't succeed :(

Thanks for getting back on this. Your observations are exactly what I see as well. A note about severity of this bug. When looking around for reasons for data loss on ceph, the number one is size=2, min_size=1 replication. The problem reported here is actually number 2! The most recent case I know of is: https://lists.ceph.io/hyperkitty/list/ceph-users@ceph.io/thread/QHFOGEKXK7VDNNSKR74BA6IIMGGIXBXA/#QHFOGEKXK7VDNNSKR74BA6IIMGGIXBXA . However, there are more, users just don't realise that they were bitten by incomplete object discovery.

The toxic ingredients are:

- EC pools (in particular with large replication factors like 8+2, 8+3)
- adding new OSDs/rebalancing
- power outage (or many simultaneous reboots)

After such an incident, some PGs tend to remain incomplete. If OSDs then start erasing unreferenced objects, data loss occurs.

To be prepared, when adding OSDs I now use an extended procedure:

- add new OSDs outside the destination tree
- save the crush map (getcrushmap) to "map-before"
- set norebalance, ...
- move all OSDs to destination and wait for peering to finish
- save the crush map (getcrushmap) to "map-after"
- unset norebalance, ...

This way, I can very quickly switch between the before and after crush map in case something goes wrong.

I really hope you find the reason.

Given the "severity" I'd be really glad if some of the Ceph core devs could have a look at this :) I'm really not that familiar with the codebase.

I'm working on a test reproducer here: https://github.com/ceph/ceph/pull/40849

It seems it does find the data when I issue ceph pg repeer $pgid. Observed on MON 14.2.21 with all OSDs 14.2.15.

I had a look at the reproducer and am not entirely sure if it is equivalent to the problem discussed here. it might be yet another situation where peering doesn't complete. I looked at the code of the function TEST_flap_ec and would like to ask if an additional test with the following modifications can be added to the suite:

function TEST_flap_ec() {
    [...]
    # set norebalance so that we don't backfill
    ceph osd set norebalance
    wait_for_clean

    # add new OSDs
    run_osd $dir 5
    run_osd $dir 6
    wait_for_peered # wait_for_clean??

    # We now have old osds=0,...,4 and
    # new OSDs 5,6. Flapping an old osd leads to degraded objects.
    # flap osd.0 while rebalancing
    ceph osd unset norebalance
    sleep 10 # let rebalancing progress a bit
    ceph osd down 0
    wait_for_osd up 0
    wait_for_peered

    # now there should be zero undersized or degraded pgs
    # I don't recall if I saw degraded PGs or only degraded objects.
    ceph pg debug degraded_pgs_exist | grep -q FALSE
}

This is the situation where I observed non-recoverable object degradation. A similar test could be added for replicated pools.

Last week we had a power outage affecting all OSD machines in a 14.2.20 cluster. A small percentage of PGs didn't activate after the machines all booted: we had 40 undersized+degraded+remapped+backfilling+peered and 7 undersized+degraded+remapped+backfill_wait+peered.

All of those PGs activated after we issued `ceph pg repeer $pgid` on them.

Neha Ojha wrote:

Is this issue reproducible in Octopus or later?

Yes. I hit it last night. It's minced one of my ec pools quite nicely

Sorry I should add some context/data

ceph version 15.2.14 (cd3bb7e87a2f62c1b862ff3fd8b1eec13391a5be) octopus (stable)

15 OSDs
Pool is 4+2 EC

Was doing a re-balance. During this, OSD's started crashing. Systemd restarted them, but they would just crash again. Got a few different errors. Some were asserts in PG_log others were something about permissions?
Anyway I restarted the whole cluster and it came back up and stopped crashing.

But by this point I've got

[WRN] OBJECT_UNFOUND: 2880/9433453 objects unfound (0.031%)
    pg 9.95 has 19 unfound objects
    pg 9.92 has 32 unfound objects
    pg 9.84 has 35 unfound objects
    pg 9.8e has 35 unfound objects
    pg 9.88 has 23 unfound objects
    pg 9.33 has 1 unfound objects
    pg 9.3c has 17 unfound objects
    pg 9.3d has 132 unfound objects
    pg 9.3e has 80 unfound objects
    pg 9.3f has 35 unfound objects
    pg 9.39 has 235 unfound objects
    pg 9.24 has 190 unfound objects
    pg 9.20 has 31 unfound objects
    pg 9.22 has 1 unfound objects
    pg 9.2d has 10 unfound objects
    pg 9.28 has 215 unfound objects
    pg 9.29 has 1 unfound objects
    pg 9.2 has 118 unfound objects
    pg 9.1a has 121 unfound objects
    pg 9.18 has 23 unfound objects
    pg 9.1f has 65 unfound objects
    pg 9.1e has 30 unfound objects
    pg 9.1c has 23 unfound objects
    pg 9.13 has 154 unfound objects
    pg 9.30 has 168 unfound objects
    pg 9.36 has 60 unfound objects
    pg 9.34 has 8 unfound objects
    pg 9.4e has 30 unfound objects
    pg 9.47 has 17 unfound objects
    pg 9.5e has 4 unfound objects
    pg 9.51 has 32 unfound objects
    pg 9.56 has 2 unfound objects
    pg 9.54 has 50 unfound objects
    pg 9.6a has 33 unfound objects
    pg 9.6d has 1 unfound objects
    pg 9.61 has 116 unfound objects
    pg 9.67 has 76 unfound objects
    pg 9.65 has 274 unfound objects
    pg 9.79 has 111 unfound objects
    pg 9.7f has 116 unfound objects
    pg 9.7c has 36 unfound objects
    pg 9.71 has 120 unfound objects

Glad I didn't move the data I cared about into EC.

So in even more fun news, I created the EC pool according to the instructions provided in the documentation.

It's set the min_size on a pool with a k=6 to 3.

So that's fun default.

It's also set the min_size on a pool with a k=10 to 3 as well.

I'm hoping this behavior has changed.

Can you share your ec profile and the output of "ceph osd pool ls detail"?

Could somebody please set the status back to open and Affected Versions to all?

Neha Ojha wrote:

Frank Schilder wrote:

Could somebody please set the status back to open and Affected Versions to all?

The ticket is open and "Need More Info" means that we are waiting for data requested in https://tracker.ceph.com/issues/46847#note-18. I have also updated the backport field appropriately.

Just had a power outage. It was doing a rebalance. I've now got recovery_unfound pg's. I understand that it might be unhappy about that but actually losing and being unable to recover from where it was seems problematic

ceph osd pool ls detail

pool 2 'cephfs_data' replicated size 2 min_size 1 crush_rule 0 object_hash rjenkins pg_num 400 pgp_num 400 autoscale_mode warn last_change 369876 lfor 14606/14606/282614 flags hashpspool,nearfull stripe_width 0 compression_mode aggressive application cephfs
pool 3 'cephfs_metadata' replicated size 3 min_size 1 crush_rule 0 object_hash rjenkins pg_num 32 pgp_num 32 autoscale_mode on last_change 369876 lfor 0/350719/350717 flags hashpspool,nearfull stripe_width 0 application cephfs
pool 5 'rbd' replicated size 2 min_size 1 crush_rule 0 object_hash rjenkins pg_num 32 pgp_num 32 autoscale_mode on last_change 369876 lfor 14610/362720/362718 flags hashpspool,nearfull,selfmanaged_snaps stripe_width 0 compression_mode aggressive application rbd
pool 7 'kube' replicated size 2 min_size 1 crush_rule 0 object_hash rjenkins pg_num 32 pgp_num 32 autoscale_mode on last_change 369876 lfor 0/332913/332911 flags hashpspool,nearfull,selfmanaged_snaps stripe_width 0 compression_mode aggressive application rbd
pool 8 'single_fs' replicated size 1 min_size 1 crush_rule 0 object_hash rjenkins pg_num 32 pgp_num 32 autoscale_mode on last_change 369876 lfor 0/280013/280011 flags hashpspool,nearfull stripe_width 0 application cephfs
pool 9 'ec_cephfs' erasure profile malsprofile size 8 min_size 6 crush_rule 4 object_hash rjenkins pg_num 150 pgp_num 150 autoscale_mode off last_change 369876 lfor 0/286579/286720 flags hashpspool,ec_overwrites,nearfull stripe_width 24576 application cephfs

this is the ec profile in use

ceph osd erasure-code-profile get malsprofile
crush-device-class=
crush-failure-domain=osd
crush-root=default
jerasure-per-chunk-alignment=false
k=6
m=2
plugin=jerasure
technique=reed_sol_van
w=8

Oh also ceph pg repeer has not totally worked. I have a single object remaining unfound.

  data:
    pools:   6 pools, 678 pgs
    objects: 9.43M objects, 32 TiB
    usage:   52 TiB used, 6.0 TiB / 58 TiB avail
    pgs:     7/50639976 objects degraded (0.000%)
             34578/50639976 objects misplaced (0.068%)
             1/9427326 objects unfound (0.000%)
             673 active+clean
             3   active+clean+inconsistent
             1   active+recovery_unfound+degraded
             1   active+remapped+backfilling

Please notice the min_size is set k (6), so there is little redundancy guaranteed.
Anyway, are you able to reproduce / do you have any logs from this occurrence?

we also encounter the similar issue and when ecpool during rebalance; sometime (osd overload or pg peering crash), then after the osd automatically reboot, pg becomes undersize + degrade and orignial pg shard on the osd disappeared during peering.

2022-05-18 09:38:00.162 7fd4860e2700 1 osd.1011 pg_epoch: 89797 pg[4.bc3s2( v 89660'793269 (88142'790192,89660'793269] local-lis/les=86475/86476 n=73239 ec=56866/872 lis/c 86475/83075 les/c/f 86476/83486/61684 86475/89797/84889) [328,869,518,258,288,559,75,281,858,269,699,74,1018,796,462,206,765,340]/[743,526,2147483647,229,676,514,52,288,934,57,598,440,938,99,522,41,180,430]p743(0) r=-1 lpr=89797 pi=[83075,89797)/1 luod=0'0 crt=89660'793269 active+remapped mbc={}] start_peering_interval up [328,869,518,258,288,559,75,281,858,269,699,74,1018,796,462,206,765,340] -> [328,869,518,258,288,559,75,281,858,269,699,74,1018,796,462,206,765,340], acting [743,526,1011,229,676,514,52,288,934,57,598,440,938,99,522,41,180,430] -> [743,526,2147483647,229,676,514,52,288,934,57,598,440,938,99,522,41,180,430], acting_primary 743(0) -> 743, up_primary 328(0) -> 328, role 2 -> -1, features acting 4611087854035861503 upacting 4611087854035861503

originally pg shard on osd.1011, but after osd.1011 suddenlly reboot and repeer the pg, actingset says pg shard on osd.1011 becomes unavailable. This is unreasonable since the pglog must be consective during such a short downtime. and pg must become a recovering on this osd.

so is that possible when a pg during backfilling, after one osd restarting, this osd cannot enter a recovering state. Instead, it also enters backfilling even if just write one object into this pg during osd downtime.

Notes from the bug scrub:

1. There is a theoretical way to enter backfill instead of recovery in such a scenario.
2. To exclude it, logs from osd.743, for the same period (the transition to the backfill), would very useful.

The PR https://github.com/ceph/ceph/pull/40849 for adding the test was marked stale. I left a comment and it would be great if someone could have a look at it. I am actually not convinced that it is necessary to wait for a fix of a warning message in order to add this test to the suite. All versions will fail any ways until the real bug is found and fixed. I don't see a good reason for this hold up. In particular, given the severity of this long-standing issue.

In addition, my recent testing shows that there is a new related bug #56995 that was introduced with nautilus or octopus. It is present in octopus 15.2.16/17 (and almost certainly all later) versions and creates a similarly dangerous PG degradation that leads to a random loss of placement information and service outage right away for no apparent reason. This problem is not present in mimic 13.2.10.

I'm also noticing that no bug scrub seems to be going on for quite a while now. I submitted a couple of tracker items and, usually, they would at least become assigned to a project after no more than a week. This hasn't happened for months now and I'm wondering what the reason might be.