nodejs profiling unknown and unaccounted results

Question

I am running nodejs 4.4.7 LTS

I run profiler as stated here https://nodejs.org/en/docs/guides/simple-profiling/:

node --prof app.js

and then:

node --prof-process isolate-something-v8.log > processed.txt

Am I missing something for profiler or something?

What the code is about:

NodeJS app is socket.io server sending data from WEB to C++ app and vice versus.

You can see from results below, that here are high amount of unaccounted tics. What could cause that and how to know what are bottlenecks of my application in this case? What could be solution?

Code move event for unknown code: 0x61047523c0
Code move event for unknown code: 0x6104bf74a0
Statistical profiling result from isolate-000001E1507CF2D0-v8.log,     (211705 ticks, 210634 unaccounted, 0 excluded).

 [Shared libraries]:
   ticks  total  nonlib   name

 [JavaScript]:
   ticks  total  nonlib   name
     71    0.0%    0.0%  LazyCompile: *stringToBuffer *SOMETHING*\socket.io\node_modules\engine.io\node_modules\engine.io-parser\lib\index.js:359:24
     59    0.0%    0.0%  LazyCompile: listOnTimeout timers.js:56:23
     50    0.0%    0.0%  LazyCompile: *wrapper timers.js:274:19
     43    0.0%    0.0%  Stub: StringAddStub_CheckNone_NotTenured

    .
    .
    .


[C++]:
   ticks  total  nonlib   name

 [Summary]:
   ticks  total  nonlib   name
   1071    0.5%    0.5%  JavaScript
      0    0.0%    0.0%  C++
    202    0.1%    0.1%  GC
      0    0.0%          Shared libraries
  210634   99.5%          Unaccounted

 [C++ entry points]:
   ticks    cpp   total   name

 [Bottom up (heavy) profile]:
  Note: percentage shows a share of a particular caller in the total
  amount of its parent calls.
  Callers occupying less than 2.0% are not shown.

   ticks parent  name
  210634   99.5%  UNKNOWN

Answer 1

Always update to the newest stable version of any software you are using, Node.js 4.4.7 is a couple of years old.

Mike Ralphson blogs in "Node.js - a tale of two bugs" :

"It is important to run both commands with exactly the same version of Node.js.

Unfortunately, when I tried to profile converting a single file (which showed around a 100% increase in execution time), both Node.js 7.x and v8.0.0-test20170511830c4bf319 showed almost all the time as unaccounted: ...

Having exhausted my Node.js debugging skills, I asked what I could do to try and produce a minimal test-case, and if there were any major anti-patterns which could result in much worse performance in Node.js 7 and 8.

I was at this stage convinced that the problem lay either in ajv (the library used to validate JSON schemas in swagger2openapi) or should.js (the BDD test/assertion library I was using).

Ben Noordhuis added to the issue that the following command would provide more in-depth profiling information, specifically on which functions were being de-optimised, and why:

 $ node8 --trace_opt --trace_deopt swagger2openapi petstore.json 

This pointed to two lines within should.js:

 ;;; deoptimize at <D:\nodejs\swagger2openapi\node_modules\should\cjs\should.js:152:14>, no cache

 ;;; deoptimize at <D:\nodejs\swagger2openapi\node_modules\should\cjs\should.js:68:14>, no cache 

That helped narrow it down, and I soon came up with a minimal test-case which showed the regressed behaviour.

 var should = require('should'); //11.2.0

 for (var i=0;i<10000;i++) {
     i.should.not.be.type('string');
 }

Node.js contributor Anna Henningsen reported that this was reproduceable.

...

He also offered to try and back-port the fix into v8 6.0 so it could be included in the current release stream of Node.js. This effort appears to have stalled however, but the good news is that the fix is already in the nightly builds of Node.js 9.0, which include v8 6.1.

The plan was to release Node.js 8.7 with v8 6.1, which should have fixed all my problems, however, a problem has been found with the v8 escape analysis which has had to be disabled in Node.js 8.7 - potentially making this release not as fast as I'd hoped. Whether the fix from v8 6.2 will make it into Node.js 8.x before it goes LTS (Long Term Support) is still a matter of conjecture, but I leave you with the comparative timings from my use-case for Node.js 6.11.4, 8.6.0, 8.7.0 and 9.0.0-nightly.

...

If you're using an exception-based assertion tool in your development environment, or any performance-critical code which depends on thrown error stack-traces, or just wondered where your performance went since Node.js 6.x, you should definitely consider upgrading to Node.js 8.7.

• Update your Toolchain and Nodejs.

• Produce a minimal testcase to demonstrate the presence or absence of the error.

• Read the Bug Reports, Blogs and known problems for software you are using.

I've had a similar problem with gcc before, unknowns and not going deep enough or into shared libraries, I recompiled my entire Toolchain with verbose debugging (-ggdb IIRC) so I could see everything. Stripping easily removed the excess. That particular solution was useful for me since I was involved in testing and error reporting, probably not useful for the average user though it's easy enough to have multiple versions of a Toolchain.