Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Memory consumption increases when profiling in an iteration #296

Open
godiedelrio opened this issue Mar 12, 2024 · 1 comment
Open

Memory consumption increases when profiling in an iteration #296

godiedelrio opened this issue Mar 12, 2024 · 1 comment

Comments

@godiedelrio
Copy link

I used the following script to measure memory consumption when code is profiled with pyinstrument and when code is run without being profiled.

import sys


def local_alloc(n):
    x = []
    for _ in range(n):
        x.append(None)


def with_pyinstrument():
    print("Profiling with pyinstrument")
    from pyinstrument import Profiler
    for i in range(20_000):
        with Profiler() as p:
            local_alloc(i)


def without_pyinstrument():
    print("Not using pyinstrument")
    for i in range(20_000):
        local_alloc(i)


if __name__ == "__main__":
    if len(sys.argv) == 2:
        if sys.argv[1] == "pyinstrument":
            with_pyinstrument()
    else:
        without_pyinstrument()

Memory consumption when the code is being profiled with pyinstrument:

$ mprof run test_pyintstruments.py pyinstrument
mprof: Sampling memory every 0.1s
running new process
running as a Python program...
Profiling with pyinstrument

$ mprof plot -o mprofile_with_pyinstrument.png /path/to/profiling/data.dat

mprofile_with_pyinstrument

Memory consumption when the code is not being profiled:

$ mprof run test_pyintstruments.py                                        
mprof: Sampling memory every 0.1s
running new process
running as a Python program...
Not using pyinstrument

$ mprof plot -o mprofile_without_pyinstrument.png /path/to/profiling/data.dat

mprofile_without_pyinstrument

What I don't understand is why memory consumption constantly increases when pyinstrument is being used, as the Profiler object is being created and destroyed in each iteration.

@leejt489
Copy link

I believe I'm having the same issue, but with a Flask app and following the documentation. This may have been introduced after moving from Python 3.6 to 3.11 or at some point in going from pyinstrument 3.0 to 4.1, but I'm not certain about that (I don't recall having this problem when I initially added this to my app in Python 3.6 with pyinstrument 3.0, but it was some time ago and it may have gone unnoticed or attributed to something else).

Looks like this SO post is describing the same problem as well.

Below is my usage, app is being served with uwsgi with 4 workers:

@app.before_request
def before_request():
    # Profile all requests when in DEBUG mode. DEBUG gets set to true by Flask if FLASK_DEBUG is True.
    # The profile will get logged for long requests in the after_request hook, or returned if requested.
    if app.config['DEBUG']:
        g.profiler = Profiler()
        g.profiler.start()
        # Mark the context to return the profile if it was requested by the args, only in DEBUG.
        if 'profile' in request.args and request.args['profile'].lower() == 'true':
            g.return_profile = True

    # Time the request.
    g.request_start_time = time()


@app.after_request
def after_request(response):
    # Return the profile html response if it was started. This uses the Slack API directly instead of the logger
    # so that it can send an attachment.
    has_profile = hasattr(g, 'profiler')
    if has_profile:
        g.profiler.stop()

    if has_profile and getattr(g, 'return_profile', False):
        return make_response(g.profiler.output_html())

    request_elapsed_time = time() - g.request_start_time
    long_request_warn = LONG_REQUEST_WARN
    if long_request_warn is not None and request_elapsed_time >= long_request_warn:
        request_start_time_str = datetime.utcfromtimestamp(g.request_start_time).isoformat()
        logging.warning(
            f'Long request encountered. Request elapsed time: {request_elapsed_time} seconds.'
            f' Request initiated at {request_start_time_str}.')
        if has_profile and SLACK_CHANNEL is not None and SLACK_TOKEN is not None:
            try:
                send_slack_file_content(
                    SLACK_TOKEN,
                    SLACK_CHANNEL,
                    g.profiler.output_html(show_all=True),
                    title=f'request_profile_{request_id()}.txt'
                )
            except SlackClientError as e:
                logging.warning('Slack Client raised an exception', exc_info=True)

    return response

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

2 participants