crimson/osd/osd_operations/snaptrim_event: lifetime fixes by Matan-B · Pull Request #54513 · ceph/ceph

Matan-B · 2023-11-15T14:30:08Z

Sanitized backtraces attached to each commit.

Contribution Guidelines

To sign and title your commits, please refer to Submitting Patches to Ceph.
If you are submitting a fix for a stable branch (e.g. "quincy"), please refer to Submitting Patches to Ceph - Backports for the proper workflow.
When filling out the below checklist, you may click boxes directly in the GitHub web UI. When entering or editing the entire PR message in the GitHub web UI editor, you may also select a checklist item by adding an x between the brackets: [x]. Spaces and capitalization matter when checking off items this way.

Checklist

Tracker (select at least one)
- References tracker ticket
- Very recent bug; references commit where it was introduced
- New feature (ticket optional)
- Doc update (no ticket needed)
- Code cleanup (no ticket needed)
Component impact
- Affects Dashboard, opened tracker ticket
- Affects Orchestrator, opened tracker ticket
- No impact that needs to be tracked
Documentation (select at least one)
- Updates relevant documentation
- No doc update is appropriate
Tests (select at least one)
- Includes unit test(s)
- Includes integration test(s)
- Includes bug reproducer
- No tests

Show available Jenkins commands

jenkins retest this please
jenkins test classic perf
jenkins test crimson perf
jenkins test signed
jenkins test make check
jenkins test make check arm64
jenkins test submodules
jenkins test dashboard
jenkins test dashboard cephadm
jenkins test api
jenkins test docs
jenkins render docs
jenkins test ceph-volume all
jenkins test ceph-volume tox
jenkins test windows
jenkins test rook e2e

Sanitized backtrace: ``` DEBUG 2023-11-14 15:23:50,871 [shard 0] osd - snaptrim_event(id=10610, detail=SnapTrimEvent(pgid=16.1a snapid=a needs_pause=0)): interrupted crimson::common::actingset_changed (acting set changed) #0 0x5653c613c071 in seastar::shared_mutex::unlock() (/usr/bin/ceph-osd+0x1ed27071) #1 0x5653c8670acf in auto seastar::futurize_invoke<crimson::OrderedConcurrentPhaseT<crimson::osd::SnapTrimEvent::WaitSubop>::ExitBarrier<crimson::OrderedConcurrentPhaseT<crimson::osd::SnapTrimEvent::WaitSubop>::BlockingEvent::Trigger<crimson::osd::SnapTrimEvent> >::exit()::{lambda()#1}&>(crimson::OrderedConcurrentPhaseT<crimson::osd::SnapTrimEvent::WaitSubop>::ExitBarrier<crimson::OrderedConcurrentPhaseT<crimson::osd::SnapTrimEvent::WaitSubop>::BlockingEvent::Trigger<crimson::osd::SnapTrimEvent> >::exit()::{lambda()#1}&) (/usr/bin/ceph-osd+0x2125bacf) #2 0x5653c8670e22 in _ZN7seastar20noncopyable_functionIFNS_6futureIvEEvEE17direct_vtable_forIZNS2_4thenIZN7crimson23OrderedConcurrentPhaseTINS7_3osd13SnapTrimEvent9WaitSubopEE11ExitBarrierINSC_13BlockingEvent7TriggerISA_EEE4exitEvEUlvE_S2_EET0_OT_EUlDpOT_E_E4callEPKS4_ (/usr/bin/ceph-osd+0x2125be22) freed by thread T1 here: #0 0x7f10628b73cf in operator delete(void*, unsigned long) (/lib64/libasan.so.6+0xb73cf) #1 0x5653c8794bff in crimson::osd::SnapTrimEvent::~SnapTrimEvent() (/usr/bin/ceph-osd+0x2137fbff) previously allocated by thread T1 here: #0 0x7f10628b6367 in operator new(unsigned long) (/lib64/libasan.so.6+0xb6367) SUMMARY: AddressSanitizer: heap-use-after-free (/usr/bin/ceph-osd+0x1ed27071) in seastar::shared_mutex::unlock() ``` Signed-off-by: Matan Breizman <mbreizma@redhat.com>

src/crimson/osd/osd_operations/snaptrim_event.cc

src/crimson/osd/pg.cc

Signed-off-by: Matan Breizman <mbreizma@redhat.com>

``` // SnapTrimEvent is a background operation, // it's lifetime is not guarnteed since the caller // returned future is being ignored. We should capture // a self reference thourhgout the entire execution // progress (not only on finally() continuations). // See: PG::on_active_actmap() ``` Sanitized backtrace: ``` DEBUG 2023-11-16 08:42:48,441 [shard 0] osd - snaptrim_event(id=21122, detail=SnapTrimEvent(pgid=3.1 snapid=3cb needs_pause=1)): interrupted crimson::common::actingset_changed (acting set changed kernel callstack: #0 0x55e310e0ace7 in seastar::shared_mutex::unlock() (/usr/bin/ceph-osd+0x1edd0ce7) #1 0x55e313325d9c in auto seastar::futurize_invoke<crimson::OrderedConcurrentPhaseT<crimson::osd::SnapTrimEvent::WaitSubop>::ExitBarrier<crimson::OrderedConcurrentPhaseT<crimson::osd::SnapTrimEvent::WaitSubop>::BlockingEvent::Trigger<crimson::osd::SnapTrimEvent> >::exit()::{lambda()#1}&>(crimson::OrderedConcurrentPhaseT<crimson::osd::SnapTrimEvent::WaitSubop>::ExitBarrier<crimson::OrderedConcurrentPhaseT<crimson::osd::SnapTrimEvent::WaitSubop>::BlockingEvent::Trigger<crimson::osd::SnapTrimEvent> >::exit()::{lambda()#1}&) (/usr/bin/ceph-osd+0x212ebd9c) #2 0x55e3133260ef in _ZN7seastar20noncopyable_functionIFNS_6futureIvEEvEE17direct_vtable_forIZNS2_4thenIZN7crimson23OrderedConcurrentPhaseTINS7_3osd13SnapTrimEvent9WaitSubopEE11ExitBarrierINSC_13BlockingEvent7TriggerISA_EEE4exitEvEUlvE_S2_EET0_OT_EUlDpOT_E_E4callEPKS4_ (/usr/bin/ceph-osd+0x212ec0ef) 0x61500013365c is located 92 bytes inside of 472-byte region [0x615000133600,0x6150001337d8) freed by thread T2 here: #0 0x7fb345ab73cf in operator delete(void*, unsigned long) (/lib64/libasan.so.6+0xb73cf) #1 0x55e313474863 in crimson::osd::SnapTrimEvent::~SnapTrimEvent() (/usr/bin/ceph-osd+0x2143a863) previously allocated by thread T2 here: #0 0x7fb345ab6367 in operator new(unsigned long) (/lib64/libasan.so.6+0xb6367) #1 0x55e31183ac18 in auto crimson::OperationRegistryI::create_operation<crimson::osd::SnapTrimEvent, crimson::osd::PG*, SnapMapper&, snapid_t const&, bool const&>(crimson::osd::PG*&&, SnapMapper&, snapid_t const&, bool const&) (/usr/bin/ceph-osd+0x1f800c18) SUMMARY: AddressSanitizer: heap-use-after-free (/usr/bin/ceph-osd+0x1edd0ce7) in seastar::shared_mutex::unlock() ``` Signed-off-by: Matan Breizman <mbreizma@redhat.com>

cyx1231st · 2023-11-20T03:29:01Z

src/crimson/osd/osd_operations/snaptrim_event.cc

      });
    });
-  }, [this](std::exception_ptr eptr) -> snap_trim_ertr::future<seastar::stop_iteration> {
+  }, [this, ref]


Does the issue disappear after this commit?

But my understanding is that capturing ref in the finally() continuation below should make it unnecessary to capture ref in the middle continuations from this commit.

The backtrace in this commit (abceb16) occurred based on the commit that captured ref in the finaly() continuation below (84c5b6c).

See osd.3: https://pulpito.ceph.com/matan-2023-11-16_08:02:56-crimson-rados-wip-matanb-crimson-testing-11-15-distro-crimson-smithi/7460420/

Build: https://github.com/ceph/ceph-ci/commits/wip-matanb-crimson-testing-11-15
Commit: a72569d

Does the issue disappear after this commit?

According to the last round, yes.

IIUC, the capture here should be different that usual because we ignore the future returned.

void PG::on_active_actmap() { std::ignore = seastar::do_until( [this] {...}, [this] { return seastar::repeat([to_trim, needs_pause, this] { return shard_services.start_operation<SnapTrimEvent>(...)

I'm still wondering that capturing ref in finally() (L207) should extend its life until finally() is called, which implies that capturing in the previous chained continuations (L100, L204) before finally() are unnecessary.

(IIUC the std::ignore above is unrelated to this internal chaining.)

According to the last round, yes.

I'm still feeling skeptical here, but anyway, it'd be fine to go ahead and watch the future tests.

I'm still feeling skeptical here, but anyway, it'd be fine to go ahead and watch the future tests.

I run 20 thrash test (with snapshot activity) which had the crashes mentioned here, it seems that we no longer crash on these test (19/20, 1 unrelated).
https://pulpito.ceph.com/matan-2023-11-20_10:00:00-crimson-rados-wip-matanb-crimson-testing-11-19-distro-crimson-smithi/

cyx1231st · 2023-11-20T03:33:43Z

src/crimson/osd/osd_operations/snaptrim_event.cc

    logger().debug("{}: interrupted {}", *this, eptr);
    return crimson::ct_error::eagain::make();
-  }, pg).finally([this] {
+  }, pg).finally([this, ref] {


Does the issue disappear after this fix?

See https://github.com/ceph/ceph/blob/main/src/crimson/osd/shard_services.h#L164-L169

IIUC there is no difference with this change because the life of op is already extended by its caller above.

start_operation_may_interrupt is called with SnapTrimObjSubEvent ops. The fix here is for SnapTrimEvent ops. Did I understand you correctly?

Ah, sorry about refering to an irrelavent logic.

Please refer to https://github.com/ceph/ceph/blob/main/src/crimson/osd/shard_services.h#L142-L147 instead, which should be the caller of SnapTrimObjEvent::start() and has already extended its life to finally() IIUC.

Matan-B · 2023-11-20T08:23:36Z

@cyx1231st, last round of tetsting:

https://pulpito.ceph.com/matan-2023-11-19_17:04:13-crimson-rados-wip-matanb-crimson-testing-11-19-distro-crimson-smithi/

Unrelated:

7462765: https://tracker.ceph.com/issues/63556

7462768, 7462772: https://tracker.ceph.com/issues/62162

cyx1231st

LGTM from tests

cyx1231st · 2023-11-27T08:14:47Z

Looks the issue https://tracker.ceph.com/issues/63299 still persists, refer to: https://pulpito.ceph.com/yingxin-2023-11-27_02:15:02-crimson-rados-wip-yingxin-crimson-improve-mempool5-distro-default-smithi/ --- see case 7467449 and 7467459 --- failures are: seastar::shared_mutex::unlock() after ~SnapTrimEvent().

The testing branch is https://github.com/ceph/ceph-ci/commits/wip-yingxin-crimson-improve-mempool5, which should have included this PR.

Matan-B · 2023-11-27T08:58:43Z

Looks the issue https://tracker.ceph.com/issues/63299 still persists, refer to: https://pulpito.ceph.com/yingxin-2023-11-27_02:15:02-crimson-rados-wip-yingxin-crimson-improve-mempool5-distro-default-smithi/ --- see case 7467449 and 7467459 --- failures are: seastar::shared_mutex::unlock() after ~SnapTrimEvent().

The testing branch is https://github.com/ceph/ceph-ci/commits/wip-yingxin-crimson-improve-mempool5, which should have included this PR.

@cyx1231st, opened a tracker: https://tracker.ceph.com/issues/63647
Thanks!

Matan-B added the bug-fix label Nov 15, 2023

Matan-B requested review from athanatos, cyx1231st and rzarzynski November 15, 2023 14:30

Matan-B requested a review from a team as a code owner November 15, 2023 14:30

github-actions bot added the crimson label Nov 15, 2023

Matan-B force-pushed the wip-matanb-crimson-snaptrimevent-lifetime branch from 3fb3838 to 787226f Compare November 16, 2023 09:45

Matan-B changed the title ~~crimson/osd/osd_operations/snaptrim_event: fix lifetime on finally()~~ crimson/osd/osd_operations/snaptrim_event: lifetime fixes Nov 16, 2023

Matan-B mentioned this pull request Nov 16, 2023

crimson/osd: execute submit_error_log as an ExclusivePhase #54287

Merged

14 tasks

athanatos reviewed Nov 17, 2023

View reviewed changes

src/crimson/osd/osd_operations/snaptrim_event.cc Show resolved Hide resolved

athanatos reviewed Nov 17, 2023

View reviewed changes

src/crimson/osd/pg.cc Show resolved Hide resolved

Matan-B added 2 commits November 19, 2023 12:41

crimson/osd: avoid refcount mutations

3b162d3

Signed-off-by: Matan Breizman <mbreizma@redhat.com>

Matan-B force-pushed the wip-matanb-crimson-snaptrimevent-lifetime branch from 787226f to abceb16 Compare November 19, 2023 12:43

Matan-B requested a review from athanatos November 19, 2023 17:04

cyx1231st reviewed Nov 20, 2023

View reviewed changes

Matan-B requested a review from cyx1231st November 20, 2023 08:13

Matan-B added the TESTED label Nov 20, 2023

cyx1231st approved these changes Nov 21, 2023

View reviewed changes

athanatos merged commit 1ea87ba into ceph:main Nov 21, 2023

Conversation

Matan-B commented Nov 15, 2023 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Contribution Guidelines

Checklist

Uh oh!

Uh oh!

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Matan-B commented Nov 20, 2023

Uh oh!

cyx1231st left a comment

Choose a reason for hiding this comment

Uh oh!

cyx1231st commented Nov 27, 2023 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

Matan-B commented Nov 27, 2023

Uh oh!

Reviewers

Assignees

Labels

Projects

Milestone

Development

Uh oh!

3 participants

Matan-B commented Nov 15, 2023 •

edited

Loading

cyx1231st commented Nov 27, 2023 •

edited

Loading