Bug #45795
closed
PrimaryLogPG.cc: 627: FAILED ceph_assert(!get_acting_recovery_backfill().empty())
Added by Ilya Dryomov almost 4 years ago.
Updated almost 4 years ago.
Category:
Correctness/Safety
Description
I'm running into this assert while trying to exercise krbd with replica reads (particularly balanced reads):
-3> 2020-05-31T01:41:03.454+0000 7feef4815700 10 osd.4 pg_epoch: 160 pg[3.e(unlocked)] -- Watch(140522136622944,client.4455) HandleWatchTimeout
-2> 2020-05-31T01:41:03.454+0000 7feef4815700 10 osd.4 pg_epoch: 160 pg[3.e( v 160'3343 (0'0,160'3343] local-lis/les=19/20 n=217 ec=19/19 lis/c=19/19 les/c/f=20/20/0 sis=19) [7,4] r=1 lpr=19 luod=0'0 crt=160'3341 mlcod 159'3328 active
mbc={}] handle_watch_timeout obc 0x55d0e1f2f440
-1> 2020-05-31T01:41:03.462+0000 7feef4815700 -1 /build/ceph-16.0.0-2020-g64aa691/src/osd/PrimaryLogPG.cc: In function 'bool PrimaryLogPG::is_degraded_or_backfilling_object(const hobject_t&)' thread 7feef4815700 time 2020-05-31T01:41:
03.458493+0000
/build/ceph-16.0.0-2020-g64aa691/src/osd/PrimaryLogPG.cc: 627: FAILED ceph_assert(!get_acting_recovery_backfill().empty())
ceph version 16.0.0-2020-g64aa691 (64aa6910df80dea3468fff35edf20c3c10ff9b1b) pacific (dev)
1: (ceph::__ceph_assert_fail(char const*, char const*, int, char const*)+0x154) [0x55d0d40d2c8c]
2: (ceph::__ceph_assertf_fail(char const*, char const*, int, char const*, char const*, ...)+0) [0x55d0d40d2e67]
3: (()+0xb8b437) [0x55d0d424e437]
4: (PrimaryLogPG::handle_watch_timeout(std::shared_ptr<Watch>)+0xb8) [0x55d0d4276258]
5: (HandleWatchTimeout::complete(int)+0x118) [0x55d0d41e9618]
6: (SafeTimer::timer_thread()+0x1ac) [0x55d0d47b4bac]
7: (SafeTimerThread::entry()+0xd) [0x55d0d47b5f7d]
8: (()+0x76db) [0x7fef1801c6db]
9: (clone()+0x3f) [0x7fef16dbc88f]
0> 2020-05-31T01:41:03.466+0000 7feef4815700 -1 *** Caught signal (Aborted) **
in thread 7feef4815700 thread_name:safe_timer
Sam, could you please take a look?
Did that fire on the replica? At a guess, the problem is that notifies are being sent to replicas, which would be wrong.
- Description updated (diff)
Samuel Just wrote:
Did that fire on the replica? At a guess, the problem is that notifies are being sent to replicas, which would be wrong.
Yeah, I think the problem is that notifies are marked as reads (i.e. only CEPH_OSD_FLAG_READ is set), meaning that they meet the criteria for sending to replica. This is the case both in Objecter and the kernel client.
Since notifies aren't really reads and have side effects, should we look into marking them as writes?
Well, osd-side notifies are reads in that they don't result in mutation. I think lingerops in general probably should be always go to the primary.
I see. Watch being a write and notify being a read has always tripped me, but I guess I looked at it from the side effects POV and haven't considered when the actual mutation occurs.
I'll plan to implement that tomorrow.
- Assignee set to Ilya Dryomov
After more digging, this doesn't appear to be related to notifies being sent to replicas.
The issue seems to be with serving from replica when an object has an established watch. If can_serve_replica_read() check is satisfied, we look up the object context. If not found, we fetch the object_info_t and then call populate_obc_watchers() because the PG is active. populate_obc_watchers() sees the recorded watch, treats it as unconnected and arms HandleWatchTimeout. When it fires, we hit the assert.
librbd doesn't run into this issue because it sets balance/localize only on specific OSD ops. In the kernel client I took Objecter's global_op_flags approach, so balance/localize are set much more liberally (Greg introduced global_op_flags together with CEPH_OSD_FLAG_LOCALIZE_READS precisely for this purpose).
Ah, that makes sense. It should suffice to simply not populate_obc_watchers if replica.
- Pull request ID set to 35478
- Status changed from New to Fix Under Review
- Status changed from Fix Under Review to Pending Backport
- Copied to Backport #46007: octopus: PrimaryLogPG.cc: 627: FAILED ceph_assert(!get_acting_recovery_backfill().empty()) added
- Status changed from Pending Backport to Resolved
While running with --resolve-parent, the script "backport-create-issue" noticed that all backports of this issue are in status "Resolved" or "Rejected".
Also available in: Atom
PDF