Profiling Server-Side Renderer In RORP

This guide helps you profile the server-side code running in RORP node-renderer. It may help you find slow parts or bottlenecks in code.

This guide uses the RORP dummy app in profiling the server-side code.

Profiling Server-Side Code Running On Node Renderer

  1. Run node-renderer using the --inspect node option.

    Open the spec/dummy/Procfile.dev file and update the node-renderer process to run the renderer using node --inspect command. Change the following line

    node-renderer: RENDERER_LOG_LEVEL=debug yarn run node-renderer

    To

    node-renderer: RENDERER_LOG_LEVEL=debug RENDERER_PORT=3800 node --inspect client/node-renderer.js
  2. Run the App

    bin/dev
  3. Visit chrome://inspect on Chrome browser and you should see something like this:

    Chrome Inspect Tab
  4. Click the inspect link. This should open a developer tools window. Open the performance tab there

    Chrome Performance Tab
  5. Click the record button

    Chrome Performance Tab
  6. Open the web app you want to test and refresh it multiple times. We use the React on Rails Pro dummy app for this tutorial. So, we will open it in the browser by going to http://localhost:3000

    RORP Dummy App
  7. If you get any Timeout Error while visiting the page, you may need to increase the ssr_timeout in the Ruby on Rails initializer file. Running node-renderer using the --inspect flag makes it slower. So, you can increase the ssr_timeout to 10 seconds by adding the following line to config/initializers/react_on_rails_pro.rb file

    config.ssr_timeout = 10
  8. Stop performance recording

    Running profiler at the performance tab
  9. You should see something like this

    Recorded Node JS profile

Profile Analysis

You can see that there is much work done during the first request because it contains the process of uploading the component bundles and executing the server-side bundle code.

Recorded Node JS profile

By zooming into it, you can see the function that’s called buildVM (you can also search for it by clicking Ctrl+f and type the function name)

NodeJS startup code profile

All code that runs later inside that code context calls the runInContext function. Like this code that calls renderToString to render a specific react component

runInContext function profile

To check the profile of other requests, zoom into any of the following spots of work

Recorded Node JS profile

You should find a call to serverRenderReactComponent

serverRenderReactComponent function profile

If you can’t find any requests coming to the renderer server, component caching may be the cause. You can try to disable React on Rails caching by adding the following line to config/initializers/react_on_rails_pro.rb file

config.prerender_caching = false

Profiling Renderer With High Loads

To see the renderer behavior while there are many requests coming to it, you can use the ApacheBench (ab) tool that lets you make many HTTP requests to a specific end points at the same time.

  1. The ApacheBench (ab) is installed on macOS by default. You can install it on Linux by running the following command

    sudo apt-get install apache2-utils 
  2. Do all steps in Profiling Server-Side Code Running On Node Renderer section except the step number 6. Instead of opening the page in the browser, let the ab tool make many HTTP requests for you by running the following command.

    ab -n 100 -c 10 http://localhost:3000/
  3. Now, we you open the noder-renderer profile, you will see it very busy responding to all requests

    Busy renderer profile
  4. Then, you can analyze the renderer behavior of each request as stated in Profile Analysis section.

ExecJS

React on Rails Pro support profiling with ExecJS starting from version 4.0.0-rc.1. You will need to do more work to profile exec js if you are using an older version.

If you are using v4.0.0-rc.1 or later, you can enable profiler by setting the profile_server_rendering_js_code config by adding the following line to ReactOnRails initializer.

config.profile_server_rendering_js_code = true

Then, run the app you are profiling and open some pages in it. You will find many log files with the name isloate-0x*.log in the root of your app. You can use the following command to analyze the log files.

rake react_on_rails_pro:process_v8_logs

You will find all log files are converted to profile.v8log.json file and moved to the v8_profiles directory.

You can use speedscope to analyze the profile.v8log.json file. You can install speedscope by running the following command

npm install -g speedscope

Then, you can analyze the profile by running the following command

speedscope /path/to/profile.v8log.json

Profiling ExecJS with Older Versions of React on Rails Pro

If you are using an older version of React on Rails Pro, you need to do more work to profile the server-side code running in the ExecJS.

If you are using node as the runtime for ExecJS, you can enable the profiler by adding the following code on top of the ReactOnRailsPro initializer.

class CustomRuntime < ExecJS::ExternalRuntime
  def initialize
    super(
      name: 'Custom Node.js (with --prof)',
      command: ['node --prof'],
      runner_path: ExecJS.root + '/support/node_runner.js'
    )
  end
end

ExecJS.runtime = CustomRuntime.new

If you are using V8 as the runtime for ExecJS, you can enable the profiler by adding the following code on top of the ReactOnRailsPro initializer.

class CustomRuntime < ExecJS::ExternalRuntime
  def initialize
    super(
      name: 'Custom V8 (with --prof)',
      command: ['d8 --prof'],
      runner_path: ExecJS.root + '/support/v8_runner.js'
    )
  end
end

After adding the code, you can run the app and open some pages in it. You will find many log files with the name isloate-0x*.log in the root of your app. You can use the following command to analyze any log file.

node --prof-process --preprocess -j isolate*.log > profile.v8log.json
npm install -g speedscope
speedscope /path/to/profile.v8log.json