Huge performance regression from 1.8.0 to 2.1.0

[fatso83]

This bug is basically about test runtime being increased by a tenfold by upgrading from 1.8 to 2.1. The below code snippet shows two subsequent test runs, where the first is using 1.8 and the second is using 2.1.0. Run times are 4 seconds and 49 seconds, respectively.

$ time mocha --reporter dot  test/components/

(node:30245) ExperimentalWarning: queueMicrotask() is experimental.

  ․․․․․․․․․․․․․․․․․․․․․․․․․․․․․․․․․․․․․․․․․․․․․․․․․․․․․․․․․․․․․․․․․․․․․․․․․․․․․․․․․․․․․․․․․․․․․․․․․․․․․․․․․․․․․․

  110 passing (453ms)

real    0m4.418s
user    0m4.558s
sys     0m0.527s

myuser at MyUsers-iMac in ~/dev/my-proj-frontend (develop)
$ git checkout HEAD~1
Note: checking out 'HEAD~1'.

You are in 'detached HEAD' state. You can look around, make experimental
changes and commit them, and you can discard any commits you make in this
state without impacting any branches by performing another checkout.

If you want to create a new branch to retain commits you create, you may
do so (now or later) by using -b with the checkout command again. Example:

  git checkout -b <new-branch-name>

HEAD is now at ad889806 NIM-1116 Fix failing test
husky > npm run -s postcheckout (node v11.13.0)

myuser at MyUsers-iMac in ~/dev/my-proj-frontend ((ad88980...))
$ npm i &>/dev/null;time mocha --reporter dot  test/components/

(node:30317) ExperimentalWarning: queueMicrotask() is experimental.

  ․․․․․․․․․․․․․․․․․․․․․․․․․․․․․․․․․․․․․․․․․․․․․․․․․․․․․․․․․․․․․․․․․․․․․․․․․․․․․․․․․․․․․․․․․․․․․․․․․․․․․․․․․․․․․․

  110 passing (488ms)

real    0m49.267s
user    0m48.081s
sys     0m2.330s

The entire diff between from the latest commit (reverting back to the old release):

diff --git a/package-lock.json b/package-lock.json
index ecd1be6a..28dd0934 100644
--- a/package-lock.json
+++ b/package-lock.json
@@ -13186,24 +13186,21 @@
       }
     },
     "proxyquire": {
-      "version": "2.1.0",
-      "resolved": "https://registry.npmjs.org/proxyquire/-/proxyquire-2.1.0.tgz",
-      "integrity": "sha512-kptdFArCfGRtQFv3Qwjr10lwbEV0TBJYvfqzhwucyfEXqVgmnAkyEw/S3FYzR5HI9i5QOq4rcqQjZ6AlknlCDQ==",
+      "version": "1.8.0",
+      "resolved": "https://registry.npmjs.org/proxyquire/-/proxyquire-1.8.0.tgz",
+      "integrity": "sha1-AtUUpb7ZhvBMuyCTrxZ0FTX3ntw=",
       "dev": true,
       "requires": {
         "fill-keys": "^1.0.2",
         "module-not-found-error": "^1.0.0",
-        "resolve": "~1.8.1"
+        "resolve": "~1.1.7"
       },
       "dependencies": {
         "resolve": {
-          "version": "1.8.1",
-          "resolved": "https://registry.npmjs.org/resolve/-/resolve-1.8.1.tgz",
-          "integrity": "sha512-AicPrAC7Qu1JxPCZ9ZgCZlY35QgFnNqc+0LtbRNxnVw4TXvjQ72wnuL9JQcEBgXkI9JM8MsT9kaQoHcpCRJOYA==",
-          "dev": true,
-          "requires": {
-            "path-parse": "^1.0.5"
-          }
+          "version": "1.1.7",
+          "resolved": "https://registry.npmjs.org/resolve/-/resolve-1.1.7.tgz",
+          "integrity": "sha1-IDEU2CrSxe2ejgQRs5ModeiJ6Xs=",
+          "dev": true
         }
       }
     },
diff --git a/package.json b/package.json
index 25173239..fe31f64c 100644
--- a/package.json
+++ b/package.json
@@ -123,7 +123,7 @@
     "npm-run-all": "^4.1.1",
     "prettier": "^1.16.3",
     "prop-types": "^15.5.10",
-    "proxyquire": "^2.1.0",
+    "proxyquire": "^1.7.11",
     "redux-mock-store": "^1.5.3",
     "requestretry": "^1.12.2",
     "shortid": "^2.2.8",

[bendrucker]

Thanks for the report. I don’t have expect to devote time to investigating this soon but if you can contribute any performance analysis I’d be happy to work with you on improvements.

[fatso83]

At least I can try to make a somewhat reproducible test case as a starting point. I'll be back :-)

[bendrucker]

Awesome, sounds good! Wouldn’t expect anything to be in a hot path such that an order of magnitude regression would actually cause your tests to take 10x. Will be interested to see what your setup is and if this is reproducible on a micro level.

[jooj123]

Hi,

Some things i just noticed:

In a large code base with only 1 test (i deleted all the rest of the tests to do a perf test for this issue) - a simple proxyquire related test is taking over 1 minute for version 2.1

If i downgrade to 1.8 it seems to be much quicker - at around 20s (i beleive most of my 20 second overhead is a babel step)

[fatso83]

Whatever the original source of this issue was, it seems to have mostly disappeared from my codebase. The difference in time is now 25 seconds (2.1.3) vs 16 seconds (1.8.0). The 2.1.3 version is twice as fast as 2.1.0 (49 seconds). So the original 10x is down to 3x for 2.1.0 in my codebase, and 2.1.3 makes it a 1.5x.

[thlorenz]

Looked into this for a sec and the only change I can assume to introduce the perf regession is this one. Could you try to revert that commit and see if the perf improve?

I'd really like to get to the bottom of this and either make that added feature optional or improve its perf.

[fatso83]

@thlorenz Thanks for looking into this, but it's been a couple of years, and it's a bit involved to rig that project up right now. Also, the perf diff was down to 50% (judging from my last comment), so it's not that pressing.

@jooj123 might be able to be in a better position.