Tracing is a convenient way for developers to monitor and analyze application performance at runtime. Node.js offers a few options to generate and diagnose custom trace data in JavaScript applications.

The built-in trace mechanism supports centralized tracing for not only V8 and Node.js core, but also userspace code. For the userspace tracing, Node provides the async_hooks and embedder API to trace async resources. Additionally the developers can produce trace data for their own code segments which is not formally documented.

In this tutorial, follow the steps to define a new trace category, generate custom trace data into the standard Node trace log file, and visualize trace data for centralized performance analysis.

Learning objectives

After completing this guide you will know how to:

  • Define, enable, and disable a trace category in a Node application.
  • Add custom trace events and parameters into a Node application.
  • View the custom trace data generated by a Node application.

Prerequisites

To follow this tutorial, you need to have:

  • Node.js v10 – Download and install Node.js.
  • Google Chrome – Get Chrome if you do not have it on your system.
  • A basic understanding of JavaScript and Node.js.

Estimated time

This tutorial should take 20 minutes to complete — 10 minutes for the prerequisites and another 10 minutes for the guide.

Steps

Prepare the trace binding for emitting custom trace requests

  • First, create a new JavaScript file, custom_trace.js. Enter or copy/paste the following code snippets.

      // Need the trace_events binding to emit requests
      const trace_binding = process.binding('trace_events');
    
  • Prepare the trace module for custom tracing enablement

      // Need the trace_events module to setup and manage custom categories
      const trace_events = require('trace_events');
    
  • Create custom tracing

      // Now create a tracing for a custom trace category.
      const tracing = trace_events.createTracing({ categories: ['myapp.category'] });
    
  • Enable custom tracing

    You can enable the tracing for the custom category now.

      // We need to enable the tracing to make it effective.
      tracing.enable();
    
  • Define trace types and parameters

    Let’s define some variables that will be used in custom trace invocation.

      // We use the duration and counter trace event types.
      const BEFORE_EVENT = 'B'.charCodeAt(0); // B indicates the begin of a duration event
      const END_EVENT = 'E'.charCodeAt(0);  // E indicates the end of a duration event
      const COUNTER_EVENT = 'C'.charCodeAt(0); // C indicates a counter event
    
      // Next define a few variables as the emit function input parameters.
      const category = 'myapp.category'; // the trace category for my trace data
      const traceDurName = 'traceDuration'; // the trace event name for duration events
      const traceCtrName = 'traceCounter'; // the trace event name for counter events
      const traceId = 1; // you can manage trace Ids in case there are multiple trace events with the same name
      const args1 = 'recd'; // the first optional argument name
      const args2 = 'proc'; // the second optional argument name
      var data1 = 100; // the first optional argument value, string values not supported
      var data2 = 10; // the second optional argument value, string values not supported
    
  • Add trace code

    Next you will add trace code for the duration and counter events in a loop.

      // We run a code segment 4 times below to illustrate that different trace event types could be used to generate custom    trace data.
      for (let n = 0; n < 4; n++) {
      // Emit counter trace events to track the value of ctr as it increases over time
      trace_binding.emit(COUNTER_EVENT, category, traceCtrName, traceId, 'ctr', n+1);
    
      // Emit the begin of a duration trace event including a couple of custom values
      trace_binding.emit(BEFORE_EVENT, category, traceDurName, traceId, args1, data1, args2, data2);
    
      // run some custom code
      data1 += 10;
      data2 += 1;
    
      // Emit the end of a duration trace event, tracking the changes of custom values over time
      trace_binding.emit(END_EVENT, category, traceDurName, traceId, args1, data1, args2, data2);
      }
    
  • Disable custom tracing

    You can disable the custom tracing anytime without affecting other categories.

      // The tracing for this category can be disabled at the end
      tracing.disable();
    
  • Save and review

Now the coding is done. Save the file or simply copy the complete sample. Let’s do a quick review before you run it.

In this example, two trace event types are demonstrated. A counter keeps track of how many times a code segment is executed, and a duration event captures custom data at the beginning and the end of a conceptual function.

The V8 JavaScript engine supports the trace events with the following types and associated phases, details documented here. You can choose to trace any of them applying the same approach illustrated above.

  • Duration events: B (begin), E (end)
  • Complete events: X
  • Instant events: i
  • Counter events: C
  • Async events: b (nestable start), n (nestable instant), e (nestable end)
  • Flow events: s (start), t (step), f (end)
  • Sample events: P
  • Object events: N (created), O (snapshot), D (destroyed)
  • Counter events: C
  • Metadata events: M
  • Memory dump events: V (global), v (process)
  • Mark events: R
  • Clock sync events: c
  • Context events: (, )

Run the code

Run the JavaScript code you just created and observe the trace log file that’s been generated as node_trace.1.log in the current directory.

node custom_trace.js

View the trace data

The trace log file is in the json format. You can load it in chrome://tracing to verify the trace data is properly generated for your application performance analysis and tuning.

  • In chrome browser enter chrome://tracing as URL.
  • Click the Load button, navigate, and choose node_trace.1.log.
  • Select and double click one of the traceDuration boxes.
  • You will see four duration trace events with system performance data as well as the custom property values.

Summary

In this tutorial, we described how to use the trace_events binding and module to add custom trace into a Node application. You should now be able to quickly generate and view your custom trace data to help analyze and improve your Node application runtime performance.