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

Add experimental profiler under experiments.enable_profiling #1481

Merged
merged 41 commits into from Jul 28, 2022

Conversation

szokeasaurusrex
Copy link
Member

No description provided.

@sl0thentr0py
Copy link
Member

@szokeasaurusrex could you add output from a sample run here for completeness?

@szokeasaurusrex
Copy link
Member Author

Here is a sample output from profiling a Flask request. Please be aware that I am currently working on changing the output format to a JSON format that will enable us to view the profile flamegraphs in Sentry.

Time: 20467708; Stack: ['<module>(__main__) in flask:8', 'main(flask.cli) in cli.py:988', 'main(flask.cli) in cli.py:579', 'main(click.core) in core.py:1055', 'invoke(click.core) in core.py:1657', 'invoke(click.core) in core.py:1404', 'invoke(click.core) in core.py:760', 'new_func(click.decorators) in decorators.py:84', 'invoke(click.core) in core.py:760', 'run_command(flask.cli) in cli.py:854', 'run_simple(werkzeug.serving) in serving.py:1017', 'inner(werkzeug.serving) in serving.py:970', 'serve_forever(werkzeug.serving) in serving.py:724', 'serve_forever(socketserver) in socketserver.py:237', '_handle_request_noblock(socketserver) in socketserver.py:316', 'process_request(socketserver) in socketserver.py:347', 'finish_request(socketserver) in socketserver.py:360', '__init__(socketserver) in socketserver.py:747', 'handle(werkzeug.serving) in serving.py:347', 'handle(http.server) in server.py:427', 'handle_one_request(werkzeug.serving) in serving.py:379', 'run_wsgi(werkzeug.serving) in serving.py:324', 'execute(werkzeug.serving) in serving.py:313', '__call__(flask.cli) in cli.py:340', 'sentry_patched_wsgi_app(sentry_sdk.integrations.flask) in flask.py:93', '__call__(sentry_sdk.integrations.wsgi) in wsgi.py:134', '<lambda>(sentry_sdk.integrations.flask) in flask.py:93', '__call__(flask.app) in app.py:2095', 'wsgi_app(flask.app) in app.py:2077', 'full_dispatch_request(flask.app) in app.py:1523', 'dispatch_request(flask.app) in app.py:1509', 'hello_world(app) in app.py:23']
Time: 33102583; Stack: ['<module>(__main__) in flask:8', 'main(flask.cli) in cli.py:988', 'main(flask.cli) in cli.py:579', 'main(click.core) in core.py:1055', 'invoke(click.core) in core.py:1657', 'invoke(click.core) in core.py:1404', 'invoke(click.core) in core.py:760', 'new_func(click.decorators) in decorators.py:84', 'invoke(click.core) in core.py:760', 'run_command(flask.cli) in cli.py:854', 'run_simple(werkzeug.serving) in serving.py:1017', 'inner(werkzeug.serving) in serving.py:970', 'serve_forever(werkzeug.serving) in serving.py:724', 'serve_forever(socketserver) in socketserver.py:237', '_handle_request_noblock(socketserver) in socketserver.py:316', 'process_request(socketserver) in socketserver.py:347', 'finish_request(socketserver) in socketserver.py:360', '__init__(socketserver) in socketserver.py:747', 'handle(werkzeug.serving) in serving.py:347', 'handle(http.server) in server.py:427', 'handle_one_request(werkzeug.serving) in serving.py:379', 'run_wsgi(werkzeug.serving) in serving.py:324', 'execute(werkzeug.serving) in serving.py:313', '__call__(flask.cli) in cli.py:340', 'sentry_patched_wsgi_app(sentry_sdk.integrations.flask) in flask.py:93', '__call__(sentry_sdk.integrations.wsgi) in wsgi.py:134', '<lambda>(sentry_sdk.integrations.flask) in flask.py:93', '__call__(flask.app) in app.py:2095', 'wsgi_app(flask.app) in app.py:2077', 'full_dispatch_request(flask.app) in app.py:1523', 'dispatch_request(flask.app) in app.py:1509', 'hello_world(app) in app.py:23']
Time: 43342500; Stack: ['<module>(__main__) in flask:8', 'main(flask.cli) in cli.py:988', 'main(flask.cli) in cli.py:579', 'main(click.core) in core.py:1055', 'invoke(click.core) in core.py:1657', 'invoke(click.core) in core.py:1404', 'invoke(click.core) in core.py:760', 'new_func(click.decorators) in decorators.py:84', 'invoke(click.core) in core.py:760', 'run_command(flask.cli) in cli.py:854', 'run_simple(werkzeug.serving) in serving.py:1017', 'inner(werkzeug.serving) in serving.py:970', 'serve_forever(werkzeug.serving) in serving.py:724', 'serve_forever(socketserver) in socketserver.py:237', '_handle_request_noblock(socketserver) in socketserver.py:316', 'process_request(socketserver) in socketserver.py:347', 'finish_request(socketserver) in socketserver.py:360', '__init__(socketserver) in socketserver.py:747', 'handle(werkzeug.serving) in serving.py:347', 'handle(http.server) in server.py:427', 'handle_one_request(werkzeug.serving) in serving.py:379', 'run_wsgi(werkzeug.serving) in serving.py:324', 'execute(werkzeug.serving) in serving.py:313', '__call__(flask.cli) in cli.py:340', 'sentry_patched_wsgi_app(sentry_sdk.integrations.flask) in flask.py:93', '__call__(sentry_sdk.integrations.wsgi) in wsgi.py:141', '__exit__(sentry_sdk.tracing) in tracing.py:166', 'finish(sentry_sdk.tracing) in tracing.py:602', 'get_trace_context(sentry_sdk.tracing) in tracing.py:471', 'get_or_set_sentry_tracestate(sentry_sdk.tracing) in tracing.py:354', 'compute_tracestate_entry(sentry_sdk.tracing_utils) in tracing_utils.py:341', 'compute_tracestate_value(sentry_sdk.tracing_utils) in tracing_utils.py:292', 'dumps(json) in __init__.py:234', '__init__(json.encoder) in encoder.py:104']

Copy link
Member

@sl0thentr0py sl0thentr0py left a comment

Choose a reason for hiding this comment

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

again some minor code style, everything looks good otherwise!
very cool work :)

sentry_sdk/integrations/wsgi.py Outdated Show resolved Hide resolved
sentry_sdk/profiler.py Outdated Show resolved Hide resolved
sentry_sdk/profiler.py Outdated Show resolved Hide resolved
Copy link
Member

@sl0thentr0py sl0thentr0py left a comment

Choose a reason for hiding this comment

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

let's move this to experimental.
also, can you add at least one integration test here that when the experimental flag is on, you get the profiling object in the envelope.
(ping me if you can't figure out how to do something in pytest)

@@ -78,6 +78,7 @@ def __init__(
auto_enabling_integrations=True, # type: bool
auto_session_tracking=True, # type: bool
send_client_reports=True, # type: bool
enable_profiling=False, # type: bool
Copy link
Member

Choose a reason for hiding this comment

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

we decided this should move to experimental so please move it here

Experiments = TypedDict(
"Experiments",
{
"max_spans": Optional[int],
"record_sql_params": Optional[bool],
"smart_transaction_trimming": Optional[bool],
"propagate_tracestate": Optional[bool],
"custom_measurements": Optional[bool],
},
total=False,
)

and change the checks in the context manager and tracing.py accordingly

@sl0thentr0py sl0thentr0py marked this pull request as ready for review July 22, 2022 09:57
@szokeasaurusrex
Copy link
Member Author

@sl0thentr0py I moved the enable_profiling flag to _experiments, as requested. I also had to make several changes to get CI to pass since you first approved this PR, and I would appreciate if you could look over those changes when you next review this code

@szokeasaurusrex
Copy link
Member Author

szokeasaurusrex commented Jul 27, 2022

To validate the profiler, I used this Flask server (which is just a script used by the profiling team that has been wrapped within a Flask server). To verify profiles were being generated and uploaded, I ran the Flask server in single-threaded mode with flask run --without-threads. I then initiated a request to localhost:5000/ and waited for the request to finish (it took several minutes). The server log output is available here. I then opened Sentry and verified that the profile was uploaded. A screenshot of the profile is provided below.
image

I also validated that a multi-threaded server would not break with the profiler enabled. To perform this verification, I ran the server in multi-threaded mode with flask run (without the --without-threads flag this time), and I initiated a request to localhost:5000. The request was completed successfully without errors; the server log is available here. However, as expected, no profiles were generated since the server request was not being processed on the main thread.

@sl0thentr0py sl0thentr0py merged commit f9ad69c into master Jul 28, 2022
@sl0thentr0py sl0thentr0py deleted the profiling branch July 28, 2022 10:52
@sl0thentr0py sl0thentr0py changed the title Work-in-progress integration of profiler into WSGI Add experimental profiler under experiments.enable_profiling Jul 28, 2022
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

Successfully merging this pull request may close these issues.

None yet

3 participants