Sinon: Slowdown with since 8.0.0 for NodeJs 10

[Flarna]

Describe the bug
Since Sinon v8 the execution of my testsuite is significant slower if I use NodeJs 10.
If I use NodeJs 12 I don't see a significant slowdown between 8.1.1 and 7.5.0.

Sinon 8.1.1:
NodeJs 12.14.1: 15.7 seconds
NodeJs 10.18.1: 50.7 seconds

Sinon 8.0.0:
NodeJs 12.14.1: 15.4 seconds
NodeJs 10.18.1: 50.7 seconds

Sinon 7.5.0:
NodeJs 12.14.1: 19.9 seconds
NodeJs 10.18.1: 21.2 seconds

The only change between above runs is the sinon version I selected in my package.json.

As you can see NodeJs 12 got faster with sinon 8 but NodeJs 10 got significant slower.

To Reproduce
Execute mocha testsuite of my project using different versions of node.js and sinon.

Expected behavior
No significant slowdown with sinon 8 compared to sinon 7 if NodeJs 10 is used.

Screenshots
If applicable, add screenshots to help explain your problem.

Context (please complete the following information):

• Library version: 8.1.1
• Environment: linux (windows is also effected)
• Example URL:
• Other libraries you are using: mocha 7.0.0

Additional context
My project is closed source therefore I can't share it as reproducer.
I plan to investigate this further but any hints where to start would be helpful.
Maybe it's something similar then #1983?

[mroderick]

You can use npm link to use a local checkout of Sinon, and then use git bisect to find exactly the commit that caused the slowdown.

Something along the lines of:

1. git clone [email protected]:sinonjs/sinon.git
2. cd sinon
3. (sinon):npm ci
4. (sinon): npm link
5. (your project): npm link sinon
6. (your project): npm test, observe speed
7. (sinon): git bisect start
8. (sinon): git bisect good v7.5.0
9. (sinon): git bisect bad
10. (sinon): npm ci
11. (your project): npm test, observe speed
12. If slow
    
    
    
    • (sinon): git bisect bad
    
    
13. If not slow
    
    
    
    • (sinon): git bisect good
    
    
14. Repeat steps 10 - 14 until you find the first commit, where the tests are running slowly

Make sure you repeat the npm ci step, as the slowdown could be in one of Sinon's dependencies.

Once you know which commit caused the slow down, then we can analyse the changes and see what might have caused it.

[Flarna]

First bad commit seems to be d08d9ebcf9ae04b0dfadf68de26db30485454939 PR: #2130

[fatso83]

Great work finding this, @Flarna.

@mantoni might know which details might be the ones causing this, but I suspect this is up for grabs for whomever has the time to dig into it.

Until then, npm install sinon@7 :man_shrugging:

[Flarna]

looks like changing extend(proxy, spy); and extend.nonEnum(proxy, stub) in stub.js to use extend.nonEnum() is causing the slowdown.
The interesting part here is that slowdown happens only if both are changed, if just one of them uses nonEnum it's slightly slower but just about 10%.

[Flarna]

I played around a little to improve this but till now I failed.
I found an issue in v8 issue tracker which indicates that Object.defineProperty is simply slow but numbers mentioned there differ to my results so maybe there is more then this.

[mroderick]

I found an old jsperf test that shows that Object.defineProperty is not cheap.

https://jsperf.com/object-defineproperty-vs-assignment/5

I wonder how many fakes, spies and stubs are created in @Flarna's test cases to in order to incur this kind of penalty though ...

[Flarna]

I added a counter in createStub() and result is 38257.

I'm quite sure that this is not just because Object.defineProperty is slower then simple assignment. Most likely GC gets also under some sort of pressure and the v8 in newer node.js versions can handle this better. Tests start fast but at some point of time they seem to get slower and slower.

In the end it's not that critical for me. v12 and newer run still as fast as before so for local testing/debugging I'm fine. CI servers test with v8 and v10 and they are quite ok with waiting a minute longer.

[mroderick]

I added a counter in createStub() and result is 38257.

That's an impressive amount of stubs!

Are you iterating over parts of node built-in APIs (or similar) and stubbing them out to prevent side effects, without actually caring about separating call counts and arguments?

If that's the case, perhaps you will experience a significant speedup by doing something like this:

// create a single fake that does nothing
const fake = sinon.fake();

// iterate over the object, replacing the property
for (const p in in hostObject) {
  sinon.replace(hostObject, p, fake);
}

[Flarna]

That's an impressive amount of stubs!

Seems sinon simply works too good 😁

We stub a native extension.
In most cases to avoid side effects/crashes (because extension is not loaded). But spread across all tests we check for this and that call detail and/or configure a few stubs with special behavior.

For simplicity we recreate this module stubs in all testsuites having a need to interact with the native api as we had issues with missing stubs every now and then before we did this one for all approach.
But I think this is for sure an area to optimize.

[mroderick]

But spread across all tests we check for this and that call detail and/or configure a few stubs with special behavior.

In all the places where you don't monitor things or change behaviour, the trick above should be able to save you some time.

[Flarna]

Thanks! I think I found already some places where we can tune our tests here without too much side effects.
Should we leave this issue open or should I close it?

[mroderick]

Should we leave this issue open or should I close it?

Feel free to close it.

I am curious to learn what you learn about optimisations and what improvements you get. If you can find the time, would you add some more comments to this issue with your findings and results?

[Flarna]

I did some fast tries to avoid recreation of our native addon stub to frequently but failed. It's no rocket science, just quite some work to replace the always available stub by a fake and install only the needed stubs in the tests they need it.
The reachable speedup should be high.