NOTE
StrongLoop Arc and slc are no longer under active development, and will soon be deprecated. Arc's features are being included in the IBM API Connect Developer Toolkit: Please use it instead.
Skip to end of metadata
Go to start of metadata

 

Icon

Tracing is available as a beta feature.

Please contact callback@us.ibm.com to get a license for it.

Overview

See also: tracing-example-app.

The StrongLoop Arc Tracing module enables you to analyze performance and execution of Node applications to discover bottlenecks and trace code execution paths.  You can display up to five hours of data to discover how applications perform over time.

You can drill down into specific function calls and execution paths for HTTP and database requests, to see how and where your application is spending time. Tracing provides powerful "flame graph" visualization of an application's function call stack and the corresponding execution times to help you track down where the application spends its time.

Tracing monitors an application by:
  • Detecting the entry and exit points of JavaScript functions to record the elapsed time of each function call and the position of the function call in the source file.  Tracing instruments every function in your application as well as the packages your application requires. 
  • Wrapping all HTTP/HTTPS requests and database operations for supported database backends.
Icon

trace is the execution path that an application follows at runtime, including the entire function call stack.

The Tracing module displays data at several different levels:

Supported backends

The following table lists the backends for which tracing has been tested.  It may work with other versions of the stated Node drivers, but has not been tested with them.

BackendNode Driver
Memcachememcache 0.3.0
Memcachedmemcached 2.1.0
MongoDBmongodb 1.x - 2.x
MySQLmysql 2.9.0+
Oracle

oracle 0.3.8
oracledb  1.0.0

PostgreSQLpg 4.4.1
Redisredis 0.21.1
SQLitesqlite3 3.0.10

Setup

Configure license

Contact StrongLoop for a license key to use tracing.

To view tracing data for an app running locally on the same system where you're running Arc, you don't need to do anything further.

To view tracing data for a remote application running on a remote server, you must push the license key to the remote server running Process Manager.  For instructions, see Setting your license key on a remote host.

Procedure to view application tracing

Icon

Tracing does not currently work for applications run with Arc app controller. You must deploy an application to Process Manager (either locally or remotely) as described below.

To view tracing for an application:

  1. Start StrongLoop Arc.

  2. Start an instance of StrongLoop Process Manager (PM) either locally or on a remote server.  For example, the easiest way to run an app locally is:

    For more information, see Using Process Manager

  3. If you ran Process Manager with slc start, as shown in the example in step 2, skip this step.
    Otherwise, for Process Manager on a remote server, deploy your application using either Arc or slc.  For more information, see Building and deploying.
  4. In Arc, choose Process Manager in the module selector and connect to the running PM instance as described in Connecting to Process Manager from Arc.  For example, to connect to a PM running locally as shown in the example in step 2:
    • For Strong PM, enter localhost .
    • For Port, enter 8701.
  5. In Arc, choose Tracing.
  6. Click On to turn on tracing: 
    You'll see a message like
    starting tracing... 0 of 4 processes.  
    Once all processes are loaded, you will see tracing data.  It may take a few seconds to load all the processes.

The Host drop-down selector lists Process Managers to which you've connected; by default the first one is selected.  Click the Host drop-down selector to choose a different Process Manager.  

By default, the first application process ID is selected.  Click on another process ID to view data for it.

You will see the application resource consumption timeline.  

Icon

Tracing information will not automatically update. Either refresh your browser or click on a new PID to display the latest data.

Resource consumption timeline

Icon

The information shown here is similar to Viewing CPU and heap memory consumption. However, tracing enables you to "drill down" at points where you see spikes in resource consumption to help uncover the root causes. When there is anomalous memory or CPU consumption, the chart will have an orange triangle along the timeline.

Tracing also enables you to view data over a much longer period of time (up to the last five hours of application execution) to track down issues that only occur with sustained application use.

This chart shows:

  • Blue line: Total CPU use (standard Linux load average over 1 minute for all CPU cores). 
  • Orange line: Process memory consumption (in MBytes).

An orange triangle at the bottom of the chart indicates a statistical anomaly beyond a three-sigma variation.

StrongLoop collects data at approximately 20s intervals for up to 5 hrs of time. Use this chart to pick a specific time interval you want to investigate.

Mouse over the chart to display the values at each point in time, and click on a point to display details of that interval.

Trace Sequences

Icon

See Release notes for important information about trace sequences for backend persistence stores.

Click a point on the resource consumption chart to display the trace sequences at that point; for example:

This table lists all the trace sequences active in the application during the selected interval, including HTTP endpoints, database operations, and other external calls such as memcache. The number in a green circle is the number of distinct code paths in the sequence.

Click on a row in the table to display details about that trace sequence.

Click the green arrows at the upper right to move to the next and previous intervals.

The table displays for each trace sequence:

  • JS: Time spent executing JavaScript code.
  • Total: Time spent in this trace sequence.
  • Async: Percentage of time spent waiting for a callback.
  • Sync: Percentage of time spent executing synchronous code.

Click on one of the routes to display the code path executed when responding to HTTP requests to that route; for example:

Waterfalls

Displays details for the trace sequence (HTTP route, database operation or other operation) and how much time the application spent in it.

Click the right arrow to display the next trace sequence.  Click the left arrow to display the previous trace sequence. If there is only one execution path for the selected trace sequence, then the arrows are disabled.

Synchronous versus asynchronous waterfall

This section shows the elapsed time for the selected code path across asynchronous boundaries. Each continuous block of Javascript code is represented by a solid rectangle, whose length is proportional to the amount of time spent executing that code. The label of the block shows the most significant function in that sequence of code.

The top bar is the time spent initiating the original function call. The lower bar is the time spent executing the callback function, and the line connecting the two represents the time spent waiting for a response; for example, for a database server to return a value.

Asynchronous callbacks are represented by lines connecting the time of the callback being scheduled to when it was invoked.

Click the bar to display the top costs (in terms of time spent) in the Inspector.

Synchronous code flame graph

Provides rich information about the function call stack including application code and the third-party modules the code uses, enabling you to see where an app is spending the most time.

The flame graph shows each module in a different colored block.  For example, express might be shown in green, loopback in purple, and async in purple. Blocks show function names when available. Unnamed callback functions are labeled “anonymous”. The selected call is always shown in yellow.

Read the flame graph from the bottom up. The bottom rectangle is the root of the call-stack tree, the application's initial function call, functions it calls are above that, and so on. The horizontal axis is percentage of time executing a function.

Mouse over a bar to display details of that particular call in the Inspector at right.

Synchronous raw data

This section shows the time spent executing the entire JavaScript call stack, displayed as a text-based tree illustrated graphically in the Flame Graph above.

Mouse over a bar to display details of that particular call in the Inspector at right. Click on a line to keep the display at that point.

Inspector

The Inspector displays different information, depending on whether you clicked on a bar in Synchronous vs. Asynchronous Waterfall or Synchronous Code Flame Graph / Raw Data.

Synchronous vs. Asynchronous Waterfall (Event Loop) view

Inspector shows:

  • Name: Module and function with the largest self cost in this waterfall, that is, the function that has the longest time, not counting time to execute child functions.
  • Cost: Execution time in microseconds.
  • Top Costs: Percentage of time spent executing each child function.

Synchronous Code Flame Graph or Raw Data view

Inspector shows:

  • Name: Module and function names.
  • Version: Version of the module being used.
  • File Name: Javascript source code file name where the function call occurs.
  • Line and Column: Line and column in the source file where the function call occurs.
  • Total/self/child cost: Time spent executing this call stack (total), the function (self), and functions it calls (child). In the flame graph, child calls are shown above the calling function (or "self" when you select that function call).
  • Total/self/child percentage: Percentage of time spent this call stack (total), the function (self), and functions it calls (child).