{"action":"created","issue":{"url":"https://api.github.com/repos/npm/npm/issues/10380","labels_url":"https://api.github.com/repos/npm/npm/issues/10380/labels{/name}","comments_url":"https://api.github.com/repos/npm/npm/issues/10380/comments","events_url":"https://api.github.com/repos/npm/npm/issues/10380/events","html_url":"https://github.com/npm/npm/issues/10380","id":116820363,"number":10380,"title":"investigating npm 3 perf ","user":{"login":"samccone","id":883126,"avatar_url":"https://avatars.githubusercontent.com/u/883126?v=3","gravatar_id":"","url":"https://api.github.com/users/samccone","html_url":"https://github.com/samccone","followers_url":"https://api.github.com/users/samccone/followers","following_url":"https://api.github.com/users/samccone/following{/other_user}","gists_url":"https://api.github.com/users/samccone/gists{/gist_id}","starred_url":"https://api.github.com/users/samccone/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/samccone/subscriptions","organizations_url":"https://api.github.com/users/samccone/orgs","repos_url":"https://api.github.com/users/samccone/repos","events_url":"https://api.github.com/users/samccone/events{/privacy}","received_events_url":"https://api.github.com/users/samccone/received_events","type":"User","site_admin":false},"labels":[],"state":"open","locked":false,"assignee":null,"milestone":null,"comments":7,"created_at":"2015-11-13T18:14:27Z","updated_at":"2015-11-14T20:15:37Z","closed_at":null,"body":"<h3 align=\"center\">npm3 perf :mag: </h3>\r\n\r\n**TL;DR**:  We've got a network :chart_with_downwards_trend: utilization regression that's at the root of the npm3 install performance. Here's the bird's :bird: eye view:\r\n\r\n<img src=\"https://cloud.githubusercontent.com/assets/39191/11154878/cd2b88f8-89f6-11e5-877f-0988ed9181d1.png\">\r\n\r\n<i>How'd we get here? Read on…<i/>\r\n\r\n------\r\n\r\nAfter using npm3 for a while now, it is clear that there has been a slowdown in the time to install  packages. Although a level of slowdown was to be expected given the new complexity around the flat tree and deduping dependencies, a 2 - 3x (and sometimes worse) slowdown across installs has become somewhat painful across the node community. \r\n\r\nInstead of just yelling at the world, I decided to hop in and do some profiling work to better understand what is happening under the hood and observe (via profiling) the cause and perhaps just maybe some ideas to make it fast again. (yay OSS :sparkles:)\r\n\r\n#### Profiling NPM's JS Activity\r\nTo start this journey into answering the question of why something is slow, the first thing that I wanted to do was gather some numbers and some metrics. As anyone who has ever done or attempted to try to profile in node.js, you know that upon a basic google search you are immediately thrown into a dystopian world of outdated stackoverflow answers, gists that redirect to stackoverflow questions, that end in WIP, assorted comments buried deep within the threads on github, and enterprise debugging tools :( …. \r\n\r\nHowever if you are persistent you eventually will stumble upon the two magical and useful things. First, the ability to get v8 logs out of node by passing the **`--prof`** flag which gives us a dandy v8 trace you can load in `chrome://tracing`… In our case this is not so useful. \r\n\r\nThe second thing that you will find is this repo **[node-inspector/v8-profiler](https://github.com/node-inspector/v8-profiler)** which gives us exactly what we want… a CPU profile of our node process. A small patch then hooks in the instrumentation: npm 3 patch: (https://github.com/samccone/npm/commit/64cc5cadff4809dfbf5b9176976f848a324a7179) npm 2 patch (https://github.com/kdzwinel/npm/commit/3978acc6387028d85e5bcd42f4a721d1286a81b9)\r\n\r\n#### Profiling NPM's Network Activity\r\nThere was one major piece of the perf story that I was missing and that I knew was really important to get, on top of just the cpu profile, and that was the network activity. I had the hypothesis that one of the reasons why the new version of npm got slower was not due to a CPU bound issue https://github.com/npm/npm/issues/8826#issuecomment-144567668  but rather a change in how the requests to the npm registry were being made. To get a HAR dump of the process I got in touch with @kdzwinel who has been working on just this thing https://github.com/kdzwinel/betwixt . He was able to send over raw HAR dumps from both npm 2 and npm 3 :tada:\r\n\r\nFor my test case I chose to use the package **yo** https://github.com/yeoman/yo as the example. For both npm2 and npm3 I made sure to install the package with no local npm cache, and also in forced http mode (due to a limitation around the current HAR dumping)\r\n\r\nAfter gathering both of the results I was left with CPU profiles and the HAR dumps for each version of npm installing the same project under the same kind of constraints. It was now time to take a look at the numbers inside of chrome devtools profiler and a [handy HAR viewer](https://chrome.google.com/webstore/detail/http-archive-viewer/ebbdbdmhegaoooipfnjikefdpeoaidml?hl=en) to try and prove my initial hypothesis about network perf vs cpu bound perf.\r\n\r\n\r\nFirst let’s take a look at the CPU profile to see where time is being spent, and see if we can visually see a difference between what is going on in npm2 and npm3. \r\n\r\n### Results: NPM2 JS Activity \r\n\r\n![screen shot 2015-11-13 at 8 40 35 am](https://cloud.githubusercontent.com/assets/883126/11153548/8adf2dea-89ee-11e5-83fd-e5c43cb0e6bc.png)\r\n\r\n\r\n### Results: NPM3 JS Activity\r\n\r\n![screen shot 2015-11-13 at 8 40 47 am](https://cloud.githubusercontent.com/assets/883126/11153550/90339e52-89ee-11e5-8c0a-72ecb42182b7.png)\r\n\r\n\r\nWell that is interesting, npm3 seems to be a much more sparse flame chart when installing the exact same package (yo), with large gaps in between brief periods of javascript execution. When we zoom in closer to get a look at exactly what is happening between the blank spots we get our first lead\r\n\r\n![screen shot 2015-11-13 at 8 56 44 am](https://cloud.githubusercontent.com/assets/883126/11153578/b8cd1082-89ee-11e5-8024-2b1d0df832fd.png)\r\n\r\n\r\nIt looks like each of the spikes in-between the blank space on the flame chart is when npm is handling the result from the registry. This is repeated over and over again until all of the packages have been resolved….\r\n\r\nNow this pattern of downloading things, and moving on seems totally 100% reasonable, but still at this point I am not sure why there is a big difference between npm2 and npm3, why are there gaps in the timeline of npm3 and not npm2 what exactly is different? \r\n\r\nAt this point, I am pretty sure the answer to these questions is all within the HAR dump, so let's take a look.\r\n\r\n### Results: NPM2 Network Activity\r\n\r\n![screen shot 2015-11-13 at 9 31 39 am](https://cloud.githubusercontent.com/assets/883126/11153597/cc15d28c-89ee-11e5-9a03-cd7c04e817c9.png)\r\n\r\n### Results: NPM3 Network Activity\r\n\r\n![screen shot 2015-11-13 at 9 31 28 am](https://cloud.githubusercontent.com/assets/883126/11153603/d066b590-89ee-11e5-99df-64d915031a4e.png)\r\n\r\n\r\nRight off the bat you notice the difference in how the network requests are being made, instead of groups of parallel requests as in npm2, npm3 seems to be doing its requests in a serial fashion (thus taking around 4x as long), where it waits for previous requests to complete before continuing the chain of requests. I further confirmed this by zooming into the waterfall of requests in npm3 where you can pretty clearly see this exact stair stepping of dependant requests\r\n\r\nOn the initial request for yo everything lines up, we see a batch of requests for all of the root level dependency meta but after this point npm3 and npm2 diverge significantly \r\n\r\n![screenshot from 2015-11-13 09 29 48](https://cloud.githubusercontent.com/assets/883126/11153617/e7d77ffc-89ee-11e5-8042-f91c76e3fda6.png)\r\n\r\n\r\nFurther down in the chain of requests we start to see this pattern, where we make a request of a package's metadata and then make a request for the package, and then repeat the process for all of the packages dependencies. This approach of walking through the dependencies really starts to add up because it looks like every batch of requests is dependent of the previous finishing, thus if a single request takes some time (like rx in this case) it pushes the entire request start time of many other packages. \r\n\r\n![screenshot from 2015-11-13 09 30 41](https://cloud.githubusercontent.com/assets/883126/11153623/ef0847fc-89ee-11e5-86b9-1f39ff75337e.png)\r\n\r\n\r\nThe end result here, is that we end up with a very sparse dependent network requests that for packages with many dependencies such as yo, is very slow for the end user.\r\n\r\n----\r\n\r\n<h4 align=\"center\"> Closing thoughts and ideas.. :thought_balloon:  </h4>\r\n\r\nnpm3 under the hood is operating in a totally new way, and there is a cost for all of the awesome new features such as a deduped tree and a flat tree structure, however there is a pretty significant cost :moneybag: when it comes to install time. Topically it seems like investigating ways to prebundle on the server and or batch requests to the registry would boost perf significantly, there is a fixed cost per network request that npm is making and just the volume of said requests adds up quickly. Figuring out a way to cut this number would boost performance significantly :speedboat: .  \r\n\r\nThe other big takeaway here was how hard it was to get these kind of perf metrics out of node, one day this will be fixed when https://github.com/nodejs/node/issues/2546 lands…\r\n\r\nHopefully this was somewhat helpful and can help others who know the code way better than I look into the causes of these perf hits :racehorse: :chart_with_upwards_trend: .\r\n\r\n---\r\n\r\nspecial thanks to @paulirish and @kdzwinel :sparkling_heart: "},"comment":{"url":"https://api.github.com/repos/npm/npm/issues/comments/156743514","html_url":"https://github.com/npm/npm/issues/10380#issuecomment-156743514","issue_url":"https://api.github.com/repos/npm/npm/issues/10380","id":156743514,"user":{"login":"devongovett","id":19409,"avatar_url":"https://avatars.githubusercontent.com/u/19409?v=3","gravatar_id":"","url":"https://api.github.com/users/devongovett","html_url":"https://github.com/devongovett","followers_url":"https://api.github.com/users/devongovett/followers","following_url":"https://api.github.com/users/devongovett/following{/other_user}","gists_url":"https://api.github.com/users/devongovett/gists{/gist_id}","starred_url":"https://api.github.com/users/devongovett/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/devongovett/subscriptions","organizations_url":"https://api.github.com/users/devongovett/orgs","repos_url":"https://api.github.com/users/devongovett/repos","events_url":"https://api.github.com/users/devongovett/events{/privacy}","received_events_url":"https://api.github.com/users/devongovett/received_events","type":"User","site_admin":false},"created_at":"2015-11-14T20:15:37Z","updated_at":"2015-11-14T20:15:37Z","body":"I imagine this would require a significant amount of work, but one idea that would significantly improve performance, and reduce the number of requests npm needs to do when installing things, would be to do a lot more work on the server side instead of on the client. For example, when requesting a module, the server could bundle the module, and its entire dependency tree into a single tarball. This way, the npm client would only need to request the modules at the root level, and would get the rest of the tree for free. Going a step further, when requesting multiple modules, the requests could be batched so that only a single tarball of the entire dependency tree (pre-deduped by the server) could be downloaded.\r\n\r\nDoing this on the server side instead of on the client has several benefits. It would be faster (since the data is local to the server), and require fewer HTTP requests for one. But for another, it would be much easier to add future optimizations on top of. For example, the npm server could pre-render common install trees for popular modules into static tarballs that could be hosted on a CDN, requiring no work to bundle each time they are installed."}}