Tracing, Debugging and Profiling Node.js with spy-js

This post is part of a series of posts covering features in WebStorm 9 EAP:

spy-js for JavaScript and Node.js Spy-js, our “secret agent”, has done a great job at tracing, debugging and profiling front-end JavaScript code. With WebStorm 9 EAP, we’re expanding its job: there is no back-end Node.js code our 007 can’t infiltrate.

As a refresher, spy-js was introduced with WebStorm 8. It allows tracing our code without resorting to console.log, debugging it without breakpoints and profiling it without any specialized tools. When running our application with spy-js, it gathers intelligence which we can use to see exactly what was going on in our code, even if it’s no longer running.

Let’s pour a Vodka-Martini (shaken, not stirred) and see how we can use spy-js for tracing, debugging and profiling Node.js apps.

Spy-js Run Configuration for Node.js

First things first:  we will have to create a new Run Configuration of the Spy-js for Node.js type. The parameters we have to specify are very similar to a regular Node.js Run Configuration: the Node interpreter, the working directory, the path to the JavaScript file we want to execute and so on. Optionally, we can provide a spy-js configuration file and decide which TCP port it will use to do its work.

Run/Debug configuration for Spy-js with Node.js

Once that’s done, we can launch our app using this newly created Run configuration. Pressing Shift+F10 (Ctrl+R on Mac OS X) will do the trick.

The Spy-js Tool Window

After launching our application, a new tool window will open in which we can see the various types of information spy-js collects. For my Express app here, we can see from the Events Pane that the app has started from a script, as well as the different events and executions that took place while running and using the application. Hovering any event will show some useful information, like the list of scripts that participated in the execution and the time it took to run.

Node.js events

Selecting an event populates the Event Stack pane, showing the stack tree along with a short file and function name. For npm packages, the name of the module is displayed as well. We can also see the execution time of the function. Some nodes may have their execution time rendered in blue, meaning the function is responsible for more than 50% of the execution time of the expanded stack level. A perfect candidate to look into for performance optimization! Nodes rendered in red have had an unhandled exception occur.

The right-most pane shows more details about the selected stack tree node, for example the arguments passed into it.

Node.js event stack

We can use the context menu pretty much all the time for various actions, such as navigating to the package.json file, the source code for the highlighted function, and more interesting: the trace for the selected function. Press enter or use the Jump to Trace context menu of the selected node. Spy-js will show us the code with executed statements highlighted, and we can hover over variables to see their values, or over functions to see their return values. Note that we can also enable Autoscroll to Trace from the toolbar to automatically open the trace file when selecting a node.

Trace node.js function stack

From the code above, we can see the code that was executed: the “else if” block was not touched since the first condition matched for this request.

Mute Files and Modules

When using spy-js for the first time, or with modules like Express, the information shown can be overwhelming. To give you an idea, here’s the stack trace for hitting the index route in my application:

Full stack trace of Express JS

The function timings and trace of everything that happens in Express may not be of interest. By using the Mute this node module context menu on any of the Express functions, the tree will contain everything except the muted module on subsequent requests.

Filter or Mute Node module

Using the Capture Events toolbar button, we can specify the events we want to capture or filter out. The Edit Capture Exclusions option opens a dialog in which we can filter events by event names or file name.

Capture Events

Spy-js with Child Processes

Whenever we want to run parallel processes in Node.js, we can go beyond its single-threaded nature and make use of the child_process module. Consider the following (pretty much useless) code that spawns several child processes.

Node.js child process tracing debugging

When running app.js with spy-js, the Events Pane will have a node for our main program, as well as for the child processes that have been launched. We can do exactly the same things with them as we did earlier: each process will have its events listed, and we can drill down into the stack traces, mute specific modules and so on.

Child process tracing with Spy-js

Child processes support is really handy when working with Node.js cluster: spy-js intercepts child process forking deep enough to trace applications that are using Node.js cluster extensively.

Simultaneously spying on the browser and the server

With spy-js for Node.js, we can now trace, debug and profile our server-side code. It’s worth mentioning that two spy-js sessions can be launched at the same time: one for the browser and one for Node.js. This gives us a nice end-to-end view of what’s happening in our application. The spy-js tool window will show both sessions in a different tab.

Spy-js front-end and back-end

Download the latest WebStorm 9 EAP and go on a secret mission with spy-js. We would love to hear your thoughts in the comments below!

Develop with pleasure!
JetBrains WebStorm Team

This entry was posted in Cool Feature, Early Access Preview and tagged , , , , , . Bookmark the permalink.

29 Responses to Tracing, Debugging and Profiling Node.js with spy-js

  1. Pingback: WebStorm 9 EAP is Open! | JetBrains WebStorm Blog

  2. Steve says:

    Will you be integrating spy-js profiling with something like the Karma test runner. Similar to dot trace?

  3. Pingback: Live Edit Updates in WebStorm 9 — What’s New? | JetBrains WebStorm Blog

  4. Sergey says:

    All this stuff is amazing, thank you very much! Do you think it is possible to make a ‘search for’ for events window, so that you can find where file ‘jquery.js’ or ‘somethingelse.js’ was used. Now you have to mouse over each event and when you have bunch of events it is sometimes tricky to find the one you’re interested in.

  5. Pingback: Meteor Support in WebStorm 9 | JetBrains WebStorm Blog

  6. Pingback: WebStorm 9 EAP, 138.2406: spy-js code completion, CSS3 enhancements, Scratch files and… JSX | JetBrains WebStorm Blog

  7. Alex Trz says:

    Is there any repository of the spy.js agent ?
    Does it work for Node.js 0.10 and 0.11 ?

    Thanks!

  8. Sergey says:

    Is it just me or it is not possible to use files outside of the project as a main javascript file? WebStorm gives me a following error: ‘Javascript file path must be specified correctly’. http://clip2net.com/clip/m0/33855-clip-53kb.png?nocache=1

    • Ekaterina Prigara says:

      Sergey, that’s a intentional limitation. Could you please describe the use case a bit more detailed? Do you want to trace your app started using grunt serve, or do you want to trace the build tasks?

  9. kodeninja says:

    Any chance this would be available in Intellij IDEA 13 as well?

  10. Dylan Cone says:

    I’m trying to use Spy-js for node in a node application using requirejs. The application runs perfectly using a standard node configuration in run/debug modes, however when I try to run it in a Spy-js configuration, an exception is being thrown stating the requirejs object that is handed back doesn’t have a config method. This may be a bug in requirejs, but I’m wondering if anyone has run into this before.

    Thanks!

    • Dylan Cone says:

      It looks like r.js isn’t exporting the requirejs module on line 27899. I notice in the Spy-js trace that all the if/if-else branches are being evaluated and none of them are taken. Maybe the way Spy-js is being run is freaking out requirejs so that it doesn’t think that it’s running in a node environment?

      • Dylan Cone says:

        Sorry to be debugging on your blog, but it may have some value. If I force the branch to true on 27894 of r.js things work better. Requirejs exports properly and I can call config now. However the paths are screwed up. The base path is being configured to requirejs’s node_modules folder. Anyway, hope this helps you guys. Please keep me posted on this issue. Thanks!

  11. Pingback: Spy-js 2.0: New level of JavaScript tracing | JetBrains WebStorm Blog

  12. Pingback: [Webinar Recording] A Deep Dive into WebStorm 9′s New Features | JetBrains WebStorm Blog

  13. Lei Wang says:

    I have a node.js project. I can run app.js to get the server running.
    I configured to run spy-js for nodes.
    in the javascript file field, I give it ‘app.js’.
    It ran, and the spy js consoles showed up, when I evoke from browser localhost:9300/getUsers, the result returns, but nothing was captured in the spy js Trace. Am I missing anything?

    Thanks,

    • Ekaterina Prigara says:

      Spy-js for Node.js run configuration starts your node application and you don’t need to start Node.js run configuration. Do you see any other events in spy-js tool window when you start your spy-js session?

  14. Bert Casier says:

    Is it possible to specify a remote node-interpreter for Spy-js for Node
    I want to trace an application running on a vagrant instance

Leave a Reply

Your email address will not be published. Required fields are marked *