Skip to content

mgr/BaseMgrModule: Optimize CPython Call in Finish Function#54634

Merged
yuriw merged 1 commit intoceph:mainfrom
NitzanMordhai:wip-nitzan-mgr-restful-mod-leaking-memory-results
Jan 9, 2024
Merged

mgr/BaseMgrModule: Optimize CPython Call in Finish Function#54634
yuriw merged 1 commit intoceph:mainfrom
NitzanMordhai:wip-nitzan-mgr-restful-mod-leaking-memory-results

Conversation

@NitzanMordhai
Copy link
Contributor

@NitzanMordhai NitzanMordhai commented Nov 23, 2023

Remove CPython overhead packing tuple during the 'finish' function to
improve memory consumption when we deal with long-string outputs.
When modules like Restful return large amounts of output the use
of PyObject_CallFunction without createing PyObject will reduce the
time the memory held by the mgr.

Fixes: https://tracker.ceph.com/issues/59580

Validation Process:

During the validation process, I conducted tests on a cluster consisting of 12 OSDs and approximately 5000 PGs. As a result, the PG DUMP commands returned extensive outputs. To enhance memory usage and facilitate conversion, I utilized the "pg dump_json" command.

The script, when run against the Manager (mgr) without the fix, generated the following Massif output:
image

In this output, the last snapshot indicated a memory usage of 1.1GB. Notably, one of the function calls contributing to this memory usage was identified as follows:

from 722.3 MiB: MonCommandCompletion::finish(int) (BaseMgrModule.cc:97)

Subsequently, I ran the same script against the Manager with the optimized code in BaseMgrModule, resulting in the following Massif output:
image

In this optimized scenario, the maximum allocated memory was approximately 400MB, and it did not exceed this threshold. This demonstrates a significant improvement in memory usage compared to the version without the fix.

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)
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

@NitzanMordhai NitzanMordhai requested a review from a team as a code owner November 23, 2023 13:25
@NitzanMordhai NitzanMordhai force-pushed the wip-nitzan-mgr-restful-mod-leaking-memory-results branch from 0698f24 to 0b72ffa Compare November 23, 2023 15:29
@markhpc
Copy link
Member

markhpc commented Nov 23, 2023

Excellent job diagnosing this one Nitzan!

Copy link
Contributor

@tchaikov tchaikov left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

The 'finish' function previously retained memory, leading to extended holding periods by the garbage collector.

i am not sure i understand the connection between "cPython" function and memory retained by "finish" function.

could you please update the commit message to explain why we don't need to release the reference obtained by PyObject_GetAttrString()?

@NitzanMordhai
Copy link
Contributor Author

The 'finish' function previously retained memory, leading to extended holding periods by the garbage collector.

i am not sure i understand the connection between "cPython" function and memory retained by "finish" function.

could you please update the commit message to explain why we don't need to release the reference obtained by PyObject_GetAttrString()?

@tchaikov ,I'll add back the set_fn and the Py_DECREF of it, yes, its also leaking memory if we don't decrement it as well.
Thank you for the review!

@NitzanMordhai NitzanMordhai force-pushed the wip-nitzan-mgr-restful-mod-leaking-memory-results branch from 0b72ffa to 66e4220 Compare November 26, 2023 09:02
@NitzanMordhai NitzanMordhai force-pushed the wip-nitzan-mgr-restful-mod-leaking-memory-results branch from 66e4220 to 202f3b3 Compare November 28, 2023 09:47
@NitzanMordhai NitzanMordhai force-pushed the wip-nitzan-mgr-restful-mod-leaking-memory-results branch from 202f3b3 to d31c03c Compare November 28, 2023 10:02
Copy link
Contributor

@tchaikov tchaikov left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This prolonged retention caused certain modules, such as 'rest'
to encounter out-of-memory (OOM) errors when the returned results consumed
substantial memory.

prolonged retention of what? and why is it connected to the rest module? why does this issue manifest itself in pacific? is it a regression introduced by pacific?

The suggested improvement involves employing cPython calls with more efficient
memory management, addressing the issue of prolonged memory retention during
the 'finish' function execution.

please note, if we want to use capitalised character in the name, we should make it right. CPython is a Python implementation written in the C language and Python. where C should be capitalised.

and i don't quite understand how this change addresses the "prolonged memory retention during the 'finish' function execution". what is the memory use for? and how you make the GC more efficient? or shorten the life cycle of what ?

and did you manage to reproduce this issue? how is this fix connected to https://tracker.ceph.com/issues/59580 ?

EDIT, i see you managed to reproduce this issue. but i cannot find the connection between MonCommandCompletion::finish and the splot.

with self.requests_lock:
request = CommandsRequest(_request)
self.requests.append(request)
self.requests = self.requests[-self.max_requests:]
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

i'd like to see the analysis of the impact of this change.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I ran few thousand pg dump command with and without the trimming of the requests array, there is a big improvement with the trimming, users that already checked that fix as patch mentioned that it helped a bit, but the manger was still consuming more memory and finally OOM and killed.

with the trimming:
image

without the trimming:
image

Copy link
Contributor

@tchaikov tchaikov Dec 11, 2023

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

@NitzanMordhai could you please extract this commit into another PR? the massif output is great. but it is not analysis. by analysis, i mean, the pros and cons of having an unbounded trim limit, and pros and cons of having a bounded trim limit. why 500 is good enough. and explain the reason why we need to keep self.requests to reviewers.

Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I think I have the same question as @tchaikov -- as a reviewer, I don't actually know what the purpose of self.requests is. If it's safe to trim it, do we need it at all? Why is it mandatory to maintain 500 of them, but not 501?

@NitzanMordhai NitzanMordhai changed the title mgr/BaseMgrModule: Optimize cPython Call in Finish Function mgr/BaseMgrModule: Optimize CPython Call in Finish Function Nov 30, 2023
@NitzanMordhai
Copy link
Contributor Author

NitzanMordhai commented Nov 30, 2023

EDIT, i see you managed to reproduce this issue. but i cannot find the connection between MonCommandCompletion::finish and the splot.

when i checked the massif output from the users and from my reproduction of the memory grow, i found out that most of the memory grow was coming from MonCommandCompletion::finish:
97.54% (1,893,184,371B) (heap allocation functions) malloc/new/new[], --alloc-fns, etc. ->80.44% (1,561,400,518B) 0x5263C38: PyUnicode_New (in /usr/lib64/libpython3.6m.so.1.0) | ->77.37% (1,501,775,042B) 0x524EBB9: PyUnicode_DecodeUTF8Stateful (in /usr/lib64/libpython3.6m.so.1.0) | | ->77.16% (1,497,613,126B) 0x5253C65: ??? (in /usr/lib64/libpython3.6m.so.1.0) | | | ->77.15% (1,497,539,274B) 0x5262E4C: ??? (in /usr/lib64/libpython3.6m.so.1.0) | | | | ->77.15% (1,497,537,386B) 0x5253AEE: ??? (in /usr/lib64/libpython3.6m.so.1.0) | | | | | ->77.15% (1,497,537,386B) 0x525409C: ??? (in /usr/lib64/libpython3.6m.so.1.0) | | | | | ->77.15% (1,497,537,282B) 0x52543B1: _PyObject_CallFunction_SizeT (in /usr/lib64/libpython3.6m.so.1.0) | | | | | | ->77.15% (1,497,537,282B) 0x30E4F3: MonCommandCompletion::finish(int) (BaseMgrModule.cc:95) | | | | | | ->77.15% (1,497,537,282B) 0x2FA9E4: complete (Context.h:99) | | | | | | ->77.15% (1,497,537,282B) 0x2FA9E4: operator() (BaseMgrModule.cc:160) | | | | | | ->77.15% (1,497,537,282B) 0x2FA9E4: __invoke_impl<void, ceph_send_command(BaseMgrModule*, PyObject*)::<lambda(int)>::<lambda(boost::system::error_code)>, boost::system::error_code> (invoke.h:61) | | | | | | ->77.15% (1,497,537,282B) 0x2FA9E4: __invoke<ceph_send_command(BaseMgrModule*, PyObject*)::<lambda(int)>::<lambda(boost::system::error_code)>, boost::system::error_code> (invoke.h:96) | | | | | | ->77.15% (1,497,537,282B) 0x2FA9E4: __apply_impl<ceph_send_command(BaseMgrModule*, PyObject*)::<lambda(int)>::<lambda(boost::system::error_code)>, std::tuple<boost::system::error_code>, 0> (tuple:1858) | | | | | | ->77.15% (1,497,537,282B) 0x2FA9E4: apply<ceph_send_command(BaseMgrModule*, PyObject*)::<lambda(int)>::<lambda(boost::system::error_code)>, std::tuple<boost::system::error_code> > (tuple:1869) | | | | | | ->77.15% (1,497,537,282B) 0x2FA9E4: operator() (bind_handler.h:53) | | | | | | ->77.15% (1,497,537,282B) 0x2FA9E4: operator()<> (forward_handler.h:48)
image

i assumed that the args is not properly released or freed with the GC that managed by CPython, then i checked about PyObject_CallFunction and i saw we can use it and optimize the code with less conversion to python objects.

@tchaikov
Copy link
Contributor

EDIT, i see you managed to reproduce this issue. but i cannot find the connection between MonCommandCompletion::finish and the splot.

when i checked the massif output from the users and from my reproduction of the memory grow, i found out that most of the memory grow was coming from MonCommandCompletion::finish: 97.54% (1,893,184,371B) (heap allocation functions) malloc/new/new[], --alloc-fns, etc. ->80.44% (1,561,400,518B) 0x5263C38: PyUnicode_New (in /usr/lib64/libpython3.6m.so.1.0) | ->77.37% (1,501,775,042B) 0x524EBB9: PyUnicode_DecodeUTF8Stateful (in /usr/lib64/libpython3.6m.so.1.0) | | ->77.16% (1,497,613,126B) 0x5253C65: ??? (in /usr/lib64/libpython3.6m.so.1.0) | | | ->77.15% (1,497,539,274B) 0x5262E4C: ??? (in /usr/lib64/libpython3.6m.so.1.0) | | | | ->77.15% (1,497,537,386B) 0x5253AEE: ??? (in /usr/lib64/libpython3.6m.so.1.0) | | | | | ->77.15% (1,497,537,386B) 0x525409C: ??? (in /usr/lib64/libpython3.6m.so.1.0) | | | | | ->77.15% (1,497,537,282B) 0x52543B1: _PyObject_CallFunction_SizeT (in /usr/lib64/libpython3.6m.so.1.0) | | | | | | ->77.15% (1,497,537,282B) 0x30E4F3: MonCommandCompletion::finish(int) (BaseMgrModule.cc:95) | | | | | | ->77.15% (1,497,537,282B) 0x2FA9E4: complete (Context.h:99) | | | | | | ->77.15% (1,497,537,282B) 0x2FA9E4: operator() (BaseMgrModule.cc:160) | | | | | | ->77.15% (1,497,537,282B) 0x2FA9E4: __invoke_impl<void, ceph_send_command(BaseMgrModule*, PyObject*)::<lambda(int)>::<lambda(boost::system::error_code)>, boost::system::error_code> (invoke.h:61) | | | | | | ->77.15% (1,497,537,282B) 0x2FA9E4: __invoke<ceph_send_command(BaseMgrModule*, PyObject*)::<lambda(int)>::<lambda(boost::system::error_code)>, boost::system::error_code> (invoke.h:96) | | | | | | ->77.15% (1,497,537,282B) 0x2FA9E4: __apply_impl<ceph_send_command(BaseMgrModule*, PyObject*)::<lambda(int)>::<lambda(boost::system::error_code)>, std::tuple<boost::system::error_code>, 0> (tuple:1858) | | | | | | ->77.15% (1,497,537,282B) 0x2FA9E4: apply<ceph_send_command(BaseMgrModule*, PyObject*)::<lambda(int)>::<lambda(boost::system::error_code)>, std::tuple<boost::system::error_code> > (tuple:1869) | | | | | | ->77.15% (1,497,537,282B) 0x2FA9E4: operator() (bind_handler.h:53) | | | | | | ->77.15% (1,497,537,282B) 0x2FA9E4: operator()<> (forward_handler.h:48) image

i assumed that the args is not properly released or freed with the GC that managed by CPython, then i checked about PyObject_CallFunction and i saw we can use it and optimize the code with less conversion to python objects.

so this is but a guess. but the commit message does not reflect the fact that it is a guess. and it closes the issue.

what i can find in the plot and in the backtrace is that

  1. PyUnicode_New() is taking a lot of memory.
  2. ceph_send_command() is taking a lot of memory.

in your original version you were still constructing Python strings and feeding them to PyObject_CallFunction(). what you improved in the original version was noted in #54634 (comment). it didn't address either of them.

what i'd suggest is

  • make the commit message more clear. either remove the notion of "prolonged retention" , "prolonged memory retention" and "more efficient memory management", or explain them in clear words.
  • replace cPython with CPython in the commit message.
  • split the trim change into another PR.

@athanatos
Copy link
Contributor

athanatos commented Dec 20, 2023

It's not obvious to me what the leak being fixed by "mgr/BaseMgrModule: Optimize cPython Call in Finish Function" is. Your change does plausibly reduce the time during which the arguments are retained, but it doesn't obviously explain why users are observing monotonically growing memory as I don't see a path where any of those objects are leaked. Perhaps I'm missing something?

@athanatos
Copy link
Contributor

Is it possible that the main benefit of this PR is the second commit limiting the size of that requests array?

@NitzanMordhai NitzanMordhai force-pushed the wip-nitzan-mgr-restful-mod-leaking-memory-results branch from d31c03c to 9ac4c2c Compare December 21, 2023 09:56
@NitzanMordhai
Copy link
Contributor Author

@tchaikov @athanatos i split the PR as you suggested: #54984

@NitzanMordhai NitzanMordhai force-pushed the wip-nitzan-mgr-restful-mod-leaking-memory-results branch from 9ac4c2c to 8b3b77d Compare December 21, 2023 10:07
Remove CPython overhead packing tuple during the 'finish' function to
improve memory consumption when we deal with long-string outputs.
When modules like Restful return large amounts of output the use
of PyObject_CallFunction without createing PyObject will reduce the
time the memory held by the mgr.

Fixes: https://tracker.ceph.com/issues/59580
Signed-off-by: Nitzan Mordechai <nmordech@redhat.com>
@NitzanMordhai NitzanMordhai force-pushed the wip-nitzan-mgr-restful-mod-leaking-memory-results branch from 8b3b77d to 247ace1 Compare December 21, 2023 10:09
@tchaikov
Copy link
Contributor

lgtm

@tchaikov
Copy link
Contributor

tchaikov commented Dec 22, 2023

i am not sure if we should close this issue with this change though. Better off "Refs" it.

@ljflores
Copy link
Member

ljflores commented Jan 8, 2024

jenkins retest this please

@ljflores
Copy link
Member

ljflores commented Jan 8, 2024

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Projects

None yet

Development

Successfully merging this pull request may close these issues.

7 participants