Performance becomes very bad after tens of calls of scrypt()

[haoruiqian]

I encountered performance issue when using scrypt-async to crypt the password, following is the test code

var scrypt = require('scrypt-async');

var i = 0;
var count = 50;
while (i <= count) {
  var res;
  var start = Date.now();
  scrypt('HelloWorld', '39wiYWT7TxX6aflvCUk840nqmY8pm0EaC5plkK+SVyg=', {"N": 32768, "r": 8, "p": 1, dkLen: 32, encoding: 'base64', interruptStep: 0}, (derivedKey) => {
    res = derivedKey;
  });
  var end = Date.now();
  console.info('Count: ' + i + ' Time: ' + (end - start) + 'ms');
  i++;
}

After tens of calling of scrypt, the encryption time becomes 15 times more, following is the output:

Count:	0	Time:	147ms
Count:	1	Time:	145ms
Count:	2	Time:	130ms
Count:	3	Time:	125ms
Count:	4	Time:	227ms
Count:	5	Time:	165ms
Count:	6	Time:	145ms
Count:	7	Time:	148ms
Count:	8	Time:	132ms
Count:	9	Time:	119ms
Count:	10	Time:	120ms
Count:	11	Time:	137ms
Count:	12	Time:	134ms
Count:	13	Time:	149ms
Count:	14	Time:	129ms
Count:	15	Time:	143ms
Count:	16	Time:	137ms
Count:	17	Time:	134ms
Count:	18	Time:	122ms
Count:	19	Time:	126ms
Count:	20	Time:	118ms
Count:	21	Time:	128ms
Count:	22	Time:	158ms
Count:	23	Time:	139ms
Count:	24	Time:	137ms
Count:	25	Time:	127ms
Count:	26	Time:	125ms
Count:	27	Time:	124ms
Count:	28	Time:	127ms
Count:	29	Time:	125ms
Count:	30	Time:	145ms
Count:	31	Time:	159ms
Count:	32	Time:	127ms
Count:	33	Time:	126ms
Count:	34	Time:	121ms
Count:	35	Time:	131ms
Count:	36	Time:	146ms
Count:	37	Time:	128ms
Count:	38	Time:	144ms
Count:	39	Time:	154ms
Count:	40	Time:	156ms
Count:	41	Time:	161ms
Count:	42	Time:	174ms
Count:	43	Time:	2302ms
Count:	44	Time:	2333ms
Count:	45	Time:	2308ms
Count:	46	Time:	2313ms
Count:	47	Time:	2384ms
Count:	48	Time:	2291ms
Count:	49	Time:	2300ms
Count:	50	Time:	2363ms

As you can see, the beginning 43 calls just cost about 150ms in average, but from the 44th call, the time increased to 2300ms.

The scrypt-async version is 1.3.1, nodejs version 4.4.5
I'm using a MacOS, version 10.12.4 (16E195), Processor 2.8 GHz Intel Core i7, Memory 16 GB 1600 MHz DDR3.

[dchest]

Does it happen every time you try?

Can't reproduce it on 10.12.4 (16E195), 2.6 GHz Intel Core i5, 8 GB 1600 MHz DDR3, even after 500 attempts. My guess would be that it's either the garbage collector kicks in and slows things down, or your CPU is getting throttled (most likely the latter).

[haoruiqian]

Yes, I can reproduce it every time I try, I can reproduce it in a Linode VPS which has 1GB memory as well.

I tried to test with different node versions today, and this seems related to node, the performance issue happened with node version 4.4.5, if I run the test code with node 6.10.1, no performance issue.

[haoruiqian]

I used Intel Power Gadget to monitor the CPU Frequency, the Frequency increased significantly when running scrypt(), please check the screenshot

The interval inside the red rectangle is during I was running the test, seems this is not related to CPU is getting throttled?

[Tschuck]

Hi,

The same problem exists in the eth-lightwallet library. I have implemented a solution for reducing the nextTick calls to bypass the browser throttling in this area.

Look at this pull request.

[Cretezy]

This also happens on JavaScriptCore (React Native).

It doesn't seem to be a library problem, but an engine problem, unfortunately.

[innerop]

"interruptStep: 0" in the OP's code implies no calls to nextTick (just synchronous looping) so I don't understand why it would slow down after repeated calls (i.e. no nextTick throttling)