Giter VIP home page Giter VIP logo

app_profiler's Introduction

AppProfiler

Profiling is critical to providing an understanding of an application's performance.

AppProfiler aims to provide a common framework for performance profiling for Rails applications.

Installation

To install app_profiler you need to include it in your Gemfile.

Profiling middleware

Configuration

This gem automatically injects the AppProfiler::Middleware middleware into your Rails application.

This middleware can be disabled by using:

AppProfiler.middleware.disabled = true
# OR
Rails.application.config.app_profiler.middleware_disabled = true

Trigger profiling

Profiling can be triggered in one of two ways:

  1. Using the profile key in the query string of the URL.
    • Query string format: /?[key=value]&...
  2. Using the X-Profile key in the request headers.
    • X-Profile header format: [<key>=<value>];...

If async query string is provided, then the profile will be uploaded later, in an async manner. One use case for this is when we want to profile a certain % of traffic without incurring costs of inline profile uploads. Async background processing provides three callbacks:

  1. profile_enqueue_success: Called when a profile is successfully added to the queue, to be uploaded later.
  2. profile_enqueue_failure: Called when a profile fails to be enqueued due to no space left in the queue, upload_queue_max_length exceeded.
  3. after_process_queue: Called when profiles are uploaded from the background thread.

These callbacks can be configured the following manner:

AppProfiler.profile_enqueue_success = ->() {  StatsD.increment("profile_enqueue_success") }
# OR
Rails.application.config.app_profiler.profile_enqueue_success = ->() {  StatsD.increment("profile_enqueue_success") }
AppProfiler.profile_enqueue_failure = ->(profile) {  Rails.logger.info("Profile #{profile.inspect} could not be enqueued.") }
# OR
Rails.application.config.app_profiler.profile_enqueue_failure = ->(profile) {  Rails.logger.info("Profile #{profile.inspect} could not be enqueued.")}
AppProfiler.after_process_queue = ->(num_success, num_failures) { StatsD.gauge("async_profile_upload", tags: { sucessful: num_success, failed: num_failures} )}
# OR
Rails.application.config.app_profiler.after_process_queue = ->(num_success, num_failures) { StatsD.gauge("async_profile_upload", tags: { sucessful: num_success, failed: num_failures} )}

You can configure the profile header using:

AppProfiler.profile_header = "X-Profile"
# OR
Rails.application.config.app_profiler.profile_header = "X-Profile"

Here are some examples:

  1. /?profile=cpu&interval=2000&autoredirect=1&ignore_gc=1
  2. Set X-Profile to mode=wall;interval=1000;context=test-directory;autoredirect=1

Possible keys:

Key Value Notes
profile/mode Supported profiling modes: cpu, wall, object for stackprof. Use profile in (1), and mode in (2). Vernier backend only supports wall and retained at present time.
async Upload profile in a background thread. When this is set, profile redirect headers are not present in the response.
interval Sampling interval in microseconds.
ignore_gc Ignore garbage collection frames
autoredirect Redirect request automatically to Speedscope's page after profiling.
context Directory within the specified bucket in the selected storage where raw profile data should be written. Only supported in (2). Defaults to Rails.env if not specified.
backend Profiler to use, either stackprof or vernier. Defaults to stackprof. Note that Vernier requires Ruby 3.2.1+.

Note that the autoredirect feature can be turned on for all requests by doing the following:

AppProfiler.autoredirect = true
# OR
Rails.application.config.app_profiler.autoredirect = true

File names of profiles are prefixed by default with timezoned date and time, follow by profile mode, an id, and hostname of the machine where it was capture. For example: 20221006-121110-cpu-613fa8d2cdde5820d5312dea1cfa43d9-macbook-pro-work.lan.json. To customize the prefix you can provide a proc:

AppProfiler.profile_file_prefix = -> { "custom-prefix" }
# OR
Rails.application.config.app_profiler.profile_file_prefix = -> { "custom-prefix" }

To customize the redirect location you can provide a proc:

AppProfiler.profile_url_formatter = ->(upload) { "https://host.com/custom/#{upload.name}" }
# OR
Rails.application.config.app_profiler.profile_url_formatter = ->(upload) { "https://host.com/custom/#{upload.name}" }

When profiling is triggered, the middleware will generate the profile through StackProf and upload the profiles to your specified storage. For example, the default configuration would upload profiles to file storage.

When using a cloud storage provider, you can configure the target bucket name using:

AppProfiler.storage.bucket_name = "new-bucket-name"
# OR
Rails.application.config.app_profiler.storage_bucket_name = "new-bucket-name"

Access control

You may restrict the storing of profiling results by defining your own Middleware based on AppProfiler::Middleware and changing the after_profile hook method to return false for such cases.

For example, the following middleware only stores the profiling results if a disallow_profiling key was not added to the request.env while processing the request.

class AppProfilerAuthorizedMiddleware < AppProfiler::Middleware
  def after_profile(env, params)
    !env.key?("disallow_profiling")
  end
end

You can also restrict running profiling at all by using before_profile. For example you may wish to prevent anonymous users triggering the profiler:

class AppProfilerAuthorizedMiddleware < AppProfiler::Middleware
  def before_profile(env, params)
    current_user.present?
  end
end

The custom middleware can then be configured like the following:

Rails.application.config.app_profiler.middleware = AppProfilerAuthorizedMiddleware

Profile Server

This option allows for profiles to be passively collected via an HTTP endpoint, inspired by golang's built-in pprof server.

A minimal Rack app runs a minimal (non-compliant) HTTP server, which exposes an endpoint that allows for profiling. For security purposes, the server is bound to localhost only. The HTTP server is built using standard library modules only, in order to keep dependencies minimal. Because it is an entirely separate server, listening on an entirely separate socket, this should not interfere with any existing application routes, and should even be usable in non-web apps.

This allows for two main use cases:

  • Passive profile collection in production
    • Periodically profiling production apps to analyze them responding to real workloads
    • Providing a statistical, long-term view of the "hot paths" of the workload
  • Local development profiling
    • Can be used to get a profile "on demand" against a development server

Configuration

If using as a railtie, only a single option needs to be set:

config.app_profiler.server_enabled = true

Alternatively, the server can be directly started by passing in a logger as follows:

AppProfiler::Server.start(logger)

The default duration (in seconds), for requests without a duration parameter, can also be set via the railtie config.

AppProfiler.server.duration = 30
# OR
Rails.application.config.app_profiler.server_duration = 30

The server supports both TCP and Unix sockets for its transport. It is recommended to use TCP for local development, and Unix sockets for production:

AppProfiler.server.transport = AppProfiler::Server::TRANSPORT_UNIX
# OR
Rails.application.config.app_profiler.server_transport = AppProfiler::Server::TRANSPORT_UNIX

It is possible, but not recommended, to hardcode the listen port to be used in TCP server mode with:

AppProfiler.server.port = 8080
# OR
Rails.application.config.app_profiler.server_port = 8080

If this is done in production and it can cause port conflicts with multiple instances of the app, which is another reason why the Unix transport is preferred for production.

Discovering the port or socket path

In general, the server should be run without setting the port, in which case any free TCP port may be used. To determine what the port is, check the application logs, or resolve it from the special "Magic file" which contains a mapping of pid to port:

$ PID=49825
$ port_file=$(ls -1 /tmp/app_profiler/profileserver-$PID-port-*)
$ PORT=$(echo $port_file | sed 's/.*port-\([[:digit:]]*\)-.*/\1/g')
$ echo $PORT
60160

This approach is intended to be "machine friendly" so that an external profiling agent can easily detect what port to profile on.

For the Unix mode, this is even easier as the file simply includes the PID in it, and this will be the file handle to use for the Unix socket:

$ PID=41016
$ SOCK=$(ls -1d /tmp/app_profiler/* | grep $PID.sock)
$ echo $SOCK
/tmp/app_profiler/app-profiler-41016.sock

Collecting a profile

The API is very simple, and passes supported parameters directly to stackprof.

See the possible keys for additional documentation on the supported parameters.

For example, to collect a heap profile for 60 seconds, counting every 10th allocation:

curl "http://127.0.0.1:$PORT/profile?duration=60&mode=object&interval=10"

Usage with speedscope directly

By default the server will allow CORS. This can be disabled if it presents a problem, but it should be generally safe given that the server listens for requests on localhost only, which is already a private network address.

This can be used with a local instance of speedscope to directly initiate profiling from the browser. Assuming speedscope is running locally on port 9292, and the profile server is running on port 57510, the server address can be URL encoded, and passed to speedscope via #profileURL:

http://127.0.0.1:9292/#profileURL=http%3A%2F%2F127.0.0.1%3A57510%2Fprofile%3Fduration%3D1

Profiling manually

AppProfiler can be used more simply to profile blocks of code. Here's how:

report = AppProfiler.run(mode: :cpu) do
  # ...
end

report.view # opens the profile locally in speedscope.

Profile files can be found locally in your rails app at tmp/app_profiler/*.json.

Storage backends

Profiles are stored based on the defined storage class. At the moment, the gem only supports file-based and remote storage via Google Cloud Storage. the default backend is file storage.

You can use a different backend with the following configuration:

AppProfiler.storage = AppProfiler::Storage::GoogleCloudStorage
# OR
Rails.application.config.app_profiler.storage = AppProfiler::Storage::GoogleCloudStorage

Credentials for the selected storage can be set using the following configuration (Google Cloud Storage expects the path to a JSON file, or the JSON contents):

AppProfiler.storage.credentials = { "key" => "value" }
# OR
Rails.application.config.app_profiler.storage_credentials = { "key" => "value" }

Note that in development and test modes the file isn't uploaded. Instead, it is viewed via the Middleware::ViewAction. If you want to change that, use the middleware_action configuration:

Rails.application.config.app_profiler.middleware_action = AppProfiler::Middleware::UploadAction

Profiler backends

It is possible to configure AppProfiler to use the vernier or stackprof. To use vernier, it must be added separately in the application Gemfile.

The backend can be selected dynamically at runtime using the backend parameter. The default backend to use when this parameter is not specified can be configured with:

AppProfiler.backend = AppProfiler::StackprofBackend # or AppProfiler::VernierBackend
# OR
Rails.application.config.app_profiler.backend = AppProfiler::StackprofBackend # or AppProfiler::VernierBackend

By default, the stackprof backend will be used.

Running tests

bin/setup && bundle exec rake

app_profiler's People

Contributors

bmansoob avatar byroot avatar casperisfine avatar cursedcoder avatar dalehamel avatar davidstosik avatar dazworrall avatar dependabot[bot] avatar fresh-eggs avatar gmcabrita avatar gmcgibbon avatar imjching avatar imjching-shopify avatar jasonhl avatar jenshenny avatar kim76 avatar kimbilida avatar kirs avatar manuelfelipe avatar miharekar avatar pedropb avatar rafaelfranca avatar services-db[bot] avatar shioyama avatar shopify-rails[bot] avatar shopify-services avatar spike01 avatar swalkinshaw avatar tgwizard avatar

Stargazers

 avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar

Watchers

 avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar  avatar

app_profiler's Issues

Middleware's action should not be called if there are no samples in the profile

We should avoid calling the middleware's action (e.g. UploadAction) if there are no samples in the profile.

action.call(
profile,
response: response,
autoredirect: params.autoredirect,
)

When a request returns quickly during a profiling session, there is a possibility in which the profiler could not sample anything in time. There won't be any samples for those profiles, and speedscope won't recognize them either. We should drop such profiles.

One way to do so would be to return nil if the value for samples is 0 whenever profiling results are retrieved:

return unless stackprof_profile

[bug] Uploaded profiles are never unlinked

It looks like the upload process is to write a temporary file to disk, then upload it either synchronously or asynchronously.

However, I cannot find any code that actually unlinks the file after we have uploaded it.

Since profiles go to /tmp/app_profiler by default, which is probably backed by tmpfs, I wonder if we are basically leaking a small amount of memory for every profile we do, until the app restarts and /tmp is cleared.

Speedscope viewer fails for big payloads

⚠️🚨⚠️ Project/labels may still need to be added ⚠️🚨⚠️

Summary

  • David discovered a bug while profiling with AppProfiler, where the profile results could not be displayed in Spin due to an issue with large JSON files. This required the JSON file to be downloaded and opened locally with speedscope.
  • He found that when the JSON file produced by AppProfiler is too large, the javascript tag containing the flamegraph’s data isn't completely rendered.
  • David noticed that 75% of the string is lost after going through Loofah.html4_fragment and suspected that Nokogiri, which Loofah uses, may be breaking when a single line in the parsed HTML fragment is too long.
  • Mike suggested setting the HUGE parse option on the HTML4 parser, or using the HTML5 parser which does not have soft limits. In a Rails app, if on Rails 7.1, the config.action_view.sanitizer_vendor can be set to Rails::HTML5::Sanitizer to use the HTML5 parser.
  • David will check if this can be fixed in AppProfiler.

This summary was generated using OpenAI's gpt-4 with a temperature of 0.5.

🧵 Slack Thread
User Message
David Stosik
2023‑09‑22 10:06
I paired with @gmcgibbon yesterday to learn how to profile with AppProfiler, this was great, but I was nerd-sniped by the fact that we sometimes can’t show the profile results in Spin, so we need to download the JSON file and open it locally with speedscope. This is not a big deal but that shows there’s probably a bug somewhere. I dug a little bit and noticed that: • AppProfiler’s “Speedscope remote viewer” produces the `` tag that contains the flamegraph’s data here. • When the JSON file produced by AppProfiler is too big, that javascript tag is not completely rendered. However, the served page source has closing `` (generated here) tags (so Rack is probably not the problem) • the graph data read from the JSON file is passed through Sanitizer#sanitize, which is rails-html-sanitizers’ Rails::Html::SafeListSanitizer#sanitize with a reduced list of allowed tags • I decomposed the “composed sanitize” method into each part to introduce logs (see in thread). • This allowed me to notice we lose 75% of the string after going through Loofah.html4_fragment. Also, the resulting string’s size is suspiciously round (10,000,040 characters) • I experienced with Nokogiri in isolation (which is what Loofah uses), and noticed that it seems to break, maybe when a single line in the parsed HTML fragment is too long? See in thread for the debug script. @flavorjones Do you mind me picking your mind about Nokogiri? Are you aware of a line or data length limit which could break parsing?
David Stosik
2023‑09‑22 10:07
My own logs from the “decomposed sanitize method”.
David Stosik
2023‑09‑22 10:09
A minimal script to reproduce the Nokogiri problem, and its output.
== RAW HTML ==
Length: 40000064
Occurrences of 'abc ': 10000000
End of string:
c abc abc abc abc abc abc abc abc abc "


== PARSED HTML ==
Length: 10000040
Occurrences of 'abc ': 2499994
End of string:
c abc abc abc abc abc abc abc abc abc abc

Mike Dalessio
2023‑09‑22 12:39
probably have to set the HUGE parse option on the HTML4 parser
Mike Dalessio
2023‑09‑22 12:39
or use the HTML5 parser which does not have soft limits
Mike Dalessio
2023‑09‑22 12:43
in a rails app, if you're on rails 7.1, set config.action_view.sanitizer_vendor to Rails::HTML5::Sanitizer to use the HTML5 parser (see https://edgeguides.rubyonrails.[…]sanitizer-vendor)
David Stosik
2023‑09‑25 07:45
Oh that sounds right! Thank you very much! Will check if we can fix that in AppProfiler.

David Stosik archived this conversation from team-ruby-and-rails-infra at 2023‑09‑25 08:11.
All times are in UTC.

Speedscope viewing fails in development

Added app_profiler to an app, tried to profile something locally:

yarn add v1.13.0
error Running this command will add the dependency to the workspace root rather than the workspace itself, which might not be what you want - if you really meant it, make it explicit by running this command again with the -W flag (or --ignore-workspace-root-check).
info Visit https://yarnpkg.com/en/docs/cli/add for documentation about this command.
2020-07-06 18:34:36 -0400: Rack app error handling request { GET / }
#<AppProfiler::Viewer::SpeedscopeViewer::YarnError: Failed to run add --dev speedscope.>
/Users/spike/.gem/ruby/2.7.1/gems/app_profiler-0.0.5/lib/app_profiler/viewer/speedscope_viewer.rb:29:in `block in yarn'
/Users/spike/.gem/ruby/2.7.1/gems/app_profiler-0.0.5/lib/app_profiler/viewer/speedscope_viewer.rb:58:in `block in exec'
/Users/spike/.gem/ruby/2.7.1/gems/app_profiler-0.0.5/lib/app_profiler/viewer/speedscope_viewer.rb:57:in `tap'
/Users/spike/.gem/ruby/2.7.1/gems/app_profiler-0.0.5/lib/app_profiler/viewer/speedscope_viewer.rb:57:in `exec'
/Users/spike/.gem/ruby/2.7.1/gems/app_profiler-0.0.5/lib/app_profiler/viewer/speedscope_viewer.rb:28:in `yarn'
/Users/spike/.gem/ruby/2.7.1/gems/app_profiler-0.0.5/lib/app_profiler/viewer/speedscope_viewer.rb:36:in `setup_yarn'
/Users/spike/.gem/ruby/2.7.1/gems/app_profiler-0.0.5/lib/app_profiler/viewer/speedscope_viewer.rb:27:in `yarn'
/Users/spike/.gem/ruby/2.7.1/gems/app_profiler-0.0.5/lib/app_profiler/viewer/speedscope_viewer.rb:21:in `view'
/Users/spike/.gem/ruby/2.7.1/gems/app_profiler-0.0.5/lib/app_profiler/viewer/speedscope_viewer.rb:12:in `view'
/Users/spike/.gem/ruby/2.7.1/gems/app_profiler-0.0.5/lib/app_profiler/profile.rb:36:in `view'
/Users/spike/.gem/ruby/2.7.1/gems/app_profiler-0.0.5/lib/app_profiler/middleware/view_action.rb:8:in `call'
/Users/spike/.gem/ruby/2.7.1/gems/app_profiler-0.0.5/lib/app_profiler/middleware.rb:41:in `profile'
/Users/spike/.gem/ruby/2.7.1/gems/app_profiler-0.0.5/lib/app_profiler/middleware.rb:18:in `call'
/Users/spike/.gem/ruby/2.7.1/gems/railties-6.0.3.2/lib/rails/engine.rb:527:in `call'
/Users/spike/.gem/ruby/2.7.1/gems/puma-3.12.6/lib/puma/configuration.rb:227:in `call'
/Users/spike/.gem/ruby/2.7.1/gems/puma-3.12.6/lib/puma/server.rb:706:in `handle_request'
/Users/spike/.gem/ruby/2.7.1/gems/puma-3.12.6/lib/puma/server.rb:476:in `process_client'
/Users/spike/.gem/ruby/2.7.1/gems/puma-3.12.6/lib/puma/server.rb:334:in `block in run'
/Users/spike/.gem/ruby/2.7.1/gems/puma-3.12.6/lib/puma/thread_pool.rb:135:in `block in spawn_thread'

I've opened a PR (#16) that I think fixes it, but opening this issue in case the PR isn't the right way to fix it.

[bug] - Profile formatter NPE

It looks like this bug was introduced my #47

However, it sets the profile_url_formatter to a default value, so I'm a bit perplexed about why this exception occurs.

Here is an example taken from CI output after a recent gem bump:

I, [2022-06-24T16:24:22.717156 #331]  INFO -- : [Profiler] failed to upload profile error_class=NoMethodError error_message=undefined method `call' for nil:NilClass
--
  |  
  | AppProfiler.profile_url_formatter.call(upload)

This in turn seems to result in other test failures, but I believe is the actual root cause.

`AppProfiler::Server` instances leak with reforking enabled

I've noticed some File Descriptor growth in molds on pods with reforking enabled:

image

Using a heap dump and harb I was able to map it to AppProfiler::Server:

harb> rootpath 0x7f7d2327a568
root path to 0x7f7d2327a568:
                      ROOT (end_proc)
                      0x7f7d23279c30 (DATA: proc)
                      0x7f7cecb3f658 (OBJECT: AppProfiler::Server::ProfileServer)
                      0x7f7d2327a7e8 (OBJECT: AppProfiler::Server::ProfileServer::UNIX)
                      0x7f7d2327a568 (FILE: (null))

harb> rootpath 0x7f7cb1171c88
root path to 0x7f7cb1171c88:
                      ROOT (end_proc)
                      0x7f7cb1171670 (DATA: proc)
                      0x7f7d22654608 (OBJECT: AppProfiler::Server::ProfileServer)
                      0x7f7cb1171e18 (OBJECT: AppProfiler::Server::ProfileServer::UNIX)
                      0x7f7cb1171c88 (FILE: (null))

(showing only two instances here, but there is about one per generation.

I suspect the server need to be explicitly closed after fork.

[Server] Flaky test

I was looking at the flaky test here https://github.com/Shopify/app_profiler/actions/runs/6561028589/attempts/1 and was able to see (via printf debuging) that the finaliser is getting called mid test.

ObjectSpace.define_finalizer(self, self.class.unlink_socket(@socket_file, Process.pid))
.

I was able to reliably reproduce this by forcing a GC run. Looking at this https://ruby-doc.org/core-3.0.1/ObjectSpace.html#method-c-define_finalizer though, the finaliser should not run on GC?

Note that if your finalizer references the object to be finalized it will never be run on GC, although it will still be run at exit. You will get a warning if you capture the object to be finalized as the receiver of the finalizer.

Thoughts @byroot?

Recommend Projects

  • React photo React

    A declarative, efficient, and flexible JavaScript library for building user interfaces.

  • Vue.js photo Vue.js

    🖖 Vue.js is a progressive, incrementally-adoptable JavaScript framework for building UI on the web.

  • Typescript photo Typescript

    TypeScript is a superset of JavaScript that compiles to clean JavaScript output.

  • TensorFlow photo TensorFlow

    An Open Source Machine Learning Framework for Everyone

  • Django photo Django

    The Web framework for perfectionists with deadlines.

  • D3 photo D3

    Bring data to life with SVG, Canvas and HTML. 📊📈🎉

Recommend Topics

  • javascript

    JavaScript (JS) is a lightweight interpreted programming language with first-class functions.

  • web

    Some thing interesting about web. New door for the world.

  • server

    A server is a program made to process requests and deliver data to clients.

  • Machine learning

    Machine learning is a way of modeling and interpreting data that allows a piece of software to respond intelligently.

  • Game

    Some thing interesting about game, make everyone happy.

Recommend Org

  • Facebook photo Facebook

    We are working to build community through open source technology. NB: members must have two-factor auth.

  • Microsoft photo Microsoft

    Open source projects and samples from Microsoft.

  • Google photo Google

    Google ❤️ Open Source for everyone.

  • D3 photo D3

    Data-Driven Documents codes.