"Not enough data" -- how much data do I need?

[davisjam]

I am trying to use node clinic with the usual Fibonacci benchmark.

It runs 10 iterations of computing fib(30) to fib(40). This takes about 20 seconds.

Node clinic complains that there is not enough data. It does not say how much data it needs.

1. How much data does it need?
2. Can the error message be improved with an estimate of how much longer it needs to run to get enough data?

(11:29:08) jamie@woody ~/Desktop/node-profiling/benchmarks/synthetic/cpu $ time ~/Desktop/floss/node-clinic/bin.js doctor -- node app-fib.js 
Warning: Trace event is an experimental feature and could change at any time.
fib(30) = 1346269
fib(31) = 2178309
fib(32) = 3524578
fib(33) = 5702887
fib(34) = 9227465
fib(35) = 14930352
fib(36) = 24157817
fib(37) = 39088169
fib(38) = 63245986
fib(39) = 102334155
fib(30) = 1346269
fib(31) = 2178309
fib(32) = 3524578
fib(33) = 5702887
fib(34) = 9227465
fib(35) = 14930352
fib(36) = 24157817
fib(37) = 39088169
fib(38) = 63245986
fib(39) = 102334155
fib(30) = 1346269
fib(31) = 2178309
fib(32) = 3524578
fib(33) = 5702887
fib(34) = 9227465
fib(35) = 14930352
fib(36) = 24157817
fib(37) = 39088169
fib(38) = 63245986
fib(39) = 102334155
fib(30) = 1346269
fib(31) = 2178309
fib(32) = 3524578
fib(33) = 5702887
fib(34) = 9227465
fib(35) = 14930352
fib(36) = 24157817
fib(37) = 39088169
fib(38) = 63245986
fib(39) = 102334155
fib(30) = 1346269
fib(31) = 2178309
fib(32) = 3524578
fib(33) = 5702887
fib(34) = 9227465
fib(35) = 14930352
fib(36) = 24157817
fib(37) = 39088169
fib(38) = 63245986
fib(39) = 102334155
fib(30) = 1346269
fib(31) = 2178309
fib(32) = 3524578
fib(33) = 5702887
fib(34) = 9227465
fib(35) = 14930352
fib(36) = 24157817
fib(37) = 39088169
fib(38) = 63245986
fib(39) = 102334155
fib(30) = 1346269
fib(31) = 2178309
fib(32) = 3524578
fib(33) = 5702887
fib(34) = 9227465
fib(35) = 14930352
fib(36) = 24157817
fib(37) = 39088169
fib(38) = 63245986
fib(39) = 102334155
fib(30) = 1346269
fib(31) = 2178309
fib(32) = 3524578
fib(33) = 5702887
fib(34) = 9227465
fib(35) = 14930352
fib(36) = 24157817
fib(37) = 39088169
fib(38) = 63245986
fib(39) = 102334155
fib(30) = 1346269
fib(31) = 2178309
fib(32) = 3524578
fib(33) = 5702887
fib(34) = 9227465
fib(35) = 14930352
fib(36) = 24157817
fib(37) = 39088169
fib(38) = 63245986
fib(39) = 102334155
fib(30) = 1346269
fib(31) = 2178309
fib(32) = 3524578
fib(33) = 5702887
fib(34) = 9227465
fib(35) = 14930352
fib(36) = 24157817
fib(37) = 39088169
fib(38) = 63245986
fib(39) = 102334155
analysing data
/home/jamie/Desktop/floss/node-clinic/bin.js:226
        if (err) throw err
                 ^

Error: Not enough data, try running a longer benchmark
    at /home/jamie/Desktop/floss/node-clinic/node_modules/@nearform/clinic-doctor/analysis/index.js:44:29
    at /home/jamie/Desktop/floss/node-clinic/node_modules/async/dist/async.js:3874:9
    at /home/jamie/Desktop/floss/node-clinic/node_modules/async/dist/async.js:473:16
    at iterateeCallback (/home/jamie/Desktop/floss/node-clinic/node_modules/async/dist/async.js:980:24)
    at /home/jamie/Desktop/floss/node-clinic/node_modules/async/dist/async.js:958:16
    at /home/jamie/Desktop/floss/node-clinic/node_modules/async/dist/async.js:3871:13
    at Endpoint.finish (/home/jamie/Desktop/floss/node-clinic/node_modules/endpoint/endpoint.js:36:5)
    at Object.onceWrapper (events.js:272:13)
    at Endpoint.emit (events.js:185:15)
    at finishMaybe (_stream_writable.js:636:14)

real    0m18.555s
user    0m18.540s
sys 0m0.033s

[mcollina]

Can you please share the code that does that? It might be that the event loop has not run enough times to produce any meaningful data, but that's my take.

[davisjam]

The event loop runs 0 (or perhaps 1?) times.

const DO_LOG = true;

function log (msg) {
    if (DO_LOG) {
        console.error(msg);
    }
}

function fib (n) {
    if (n <= 1) {
        return 1;
    }

    return fib(n-1) + fib(n-2);
}

function main () {
    for (let i = 0; i < 10; i++) {
        for (let j = 30; j < 40; j++) {
            const res = fib(j);
            log(`fib(${j}) = ${res}`);
        }
    }
}

main();

[mcollina]

I would say that it is the main issue. clinic is truly built to diagnose Node.js applications, not fully synchronous scripts - you might want to run clinic flame directly on this type of things.

[davisjam]

Understood, though this is not really reflected in the current documentation.

From my perspective, when exploring performance tools I usually start with something like Fibonacci, so having node-clinic appear to choke on this example is a bit unnerving.

[mcollina]

Very interesting feedback, we should truly give a better output in this case. Something like:

clinic could not detect any I/O operation on this process. As such, it will be extremely hard to provide any recommendations. Consider using clinic flame directly.

Also, it should not throw an error, just fail gracefully.

From my perspective, when exploring performance tools I usually start with something like Fibonacci, so having node-clinic appear to choke on this example is a bit unnerving.

I typically use an "hello world" web server

[mafintosh]

20s of data should def be enough. I have a hunch this is caused by the profiler being started at nextTick to avoid profiling module loading. Let me investigate that a bit.

[mafintosh]

The error is being thown here, https://github.com/nearform/node-clinic/blob/master/bin.js#L226, so we should intercept that and print out a non-stack message instead

[mafintosh]

Still happens if I next the main fn, so prob something else.

[DylanC]

const DO_LOG = true;

function log (msg) {
  if (DO_LOG) {
      console.error(msg);
  }
}
function fib (n) {
  if (n <= 1) {
      return 1;
  }

  return fib(n-1) + fib(n-2);
}
function main () {
  for (let i = 0; i < 10; i++) {
      for (let j = 30; j < 40; j++) {
          const res = fib(j);
          log(`fib(${j}) = ${res}`);
      }
  }
}
main();

@mafintosh - I don't see an error being thrown here anymore. However, using the example from above we get a blank report from Doctor.