The problem
A while back, we encountered an odd problem. All of a sudden, building our front-end went from taking a few seconds to taking a few minutes. We felt this most acutely when starting our front-end development server. Incremental changes were still fast, but if you needed to stop and restart the server, it took forever. We don't do this very often in a typical day, but it turns out that having to wait for two minutes plus, even if it's only a few times in a day, really does start to slow a team down.
We're Paddy and Eoin, engineers at Tines. This is the story of how a build system issue thoroughly stumped us and eventually took us into the depths of V8 where we learned some surprising things.
The deep dive
We started, like we often do, with git bisect
. It helped us track down the set of changes that appeared to have introduced the issue; adding a Dark Mode to Tines. "This is bizarre," we thought, "how could a bunch of CSS changes have slowed things down?".
Our next step was to profile the build locally using Node DevTools. We use Webpack, so attaching a DevTools instance was as simple as running the following command and opening chrome://inspect/#devices.
node --inspect-brk ./node_modules/.bin/webpack
Using the Bottom-Up view of aggregate time spent in functions, we quickly saw that a significant amount of time was being spent in a getDependencies
function in Linaria.
As we described before, Linaria is a CSS-in-JS library we use to style our React components. It's novel in that it does all of its work at build-time, leaning heavily on CSS variables at runtime to achieve this. Our Dark Mode implementation involved creating a colour system and encoding this in CSS variables. Here's a minimal example.
import { styled } from "@linaria/react";
import React from "react";
import { render } from "react-dom";
const colors = {
darkblue: "#00008b",
ivory: "#fffff0"
};
const App = styled.div`
:global() {
body {
--textColor: ${colors.darkblue};
--backgroundColor: ${colors.ivory};
@media (prefers-color-scheme: dark) {
--textColor: ${colors.ivory};
--backgroundColor: ${colors.darkblue};
}
}
}
color: var(--textColor);
background: var(--backgroundColor);
`;
render(<App>Testing 1, 2, 3...</App>, document.querySelector("#root"));
At this point, we felt like we could be looking at a bug in Linaria (or maybe Webpack), so we created a minimal test case. This allowed us to open an issue, and continue debugging with a little more clarity.
Interestingly, the test case allowed us to establish that the slowdown only occurred on Webpack 5, not Webpack 4. This got us thinking that this might, in fact, be an issue in Webpack.
Next we focused in on getDependencies
in Linaria.
getDependencies(nodes) {
this.processQueue();
return nodes.reduce(
(acc, node) => acc.concat(Array.from(this.dependencies.get(node) || [])),
[]
);
}
With liberal use of console.timer
and console.timeEnd
, we established that concat
seemed to be where all of the time was going on Webpack 5. We'd validated that the function was being called in an identical manner on Webpack 4 and 5. This didn't make sense. We were stumped.
Looking at the function, it did seem that there was room for optimisation. "Maybe all that object creation is resulting in more GC on Webpack 5?" We went about refactoring the function to remove concat
and build the dependency array in place. Lo and behold, performance in our test case went from 16s to 1s.
We submitted a fix with the following note:
I'm pretty surprised that this has any impact, I don't have a good rationale for why but it appears to be dramatically faster to update the array in place.
While we were glad to have addressed our issue, we were very unsatisfied with the fix and our understanding (or lack thereof) of the problem. We'd a gut feeling that the root cause here might be an interesting one, so we decided to put some more time into better understanding the problem
The root cause
At this point, we were pretty suspicious of Array.concat
, so we thought we'd try to better understand how it behaved. As a built-in, this required delving into Node and V8. After poking around in the source for a while, one of the first things that stood out was the presence of Fast_ArrayConcat
and Slow_ArrayConcat
paths. "Could we be going down a slow path on Webpack 5?", we wondered. "Only one way to find out."
Building Node from source is pretty straightforward. We got it up and running in about 20 minutes. It's quite some time since either of us had worked with C++, but we remembered enough to find our way around, add some logging and rebuild. Sure enough, our test case was going down the slow path on Webpack 5, but not on Webpack 4. But why?
Looking at the implementation of Fast_ArrayConcat
it bailed immediately if a call to Protectors::IsIsConcatSpreadableLookupChainIntact
returned false
. As you might guess from its name, this function returns false
if Symbol.IsConcatSpreadable
has been set. Now, Paddy and I have been writing JavaScript near-daily for quite a number of years, and this was the first either of us had heard of Symbol.IsConcatSpreadable
. In a nutshell, it allows you to control how arguments to concat
are spread. "Could this be the culprit?"
A quick search of the Webpack source yielded a single use of Symbol.IsConcatSpreadable
. What's more, it was added in Webpack 5 in order to maintain backwards compatibility with Webpack 4. While migrating some structures from Array
to Set
, the Webpack authors required that concat
on their new Set
structures spread parameters just like Array
. A perfectly reasonable use of the symbol.
We quickly removed the usage and our test case performance went from 16s to ~1s.
This was great, but we were still confused. None of the objects in getDependencies
had Symbol.IsConcatSpreadable
set. "So why are we going down this slow path?" We looked at Protectors::IsIsConcatSpreadableLookupChainIntact
again and found something that surprised us: "Protectors" in V8 operate only at the Engine level.
💡 What this means is, if Symbol.IsConcatSpreadable
has been set anywhere in your application, on any object, to any value, any subsequent usage of concat
will go down the slow path on Node and Chrome.
const dummy = [];
dummy[Symbol.isConcatSpreadable] = true;
// Slow path on Node and Chrome
[].concat([]);
So, we had our answer. Our Dark Mode implementation (and another recent change in Linaria) had ballooned the number of nodes in Linaria's dependency graph. Calls to concat
had effectively always been slow, but this change exacerbated the problem to the point where we noticed.
Conclusion
We opened an issue for Webpack and they shipped a fix soon after. The fix, available since 5.62.0, is a new experimental configuration option backCompat
which disables backwards compatibility with Webpack 4, removing the need for the problematic code.
We were able to disable backwards compatibility without any problems, and saw an additional build time improvement beyond what we saw after the initial Linaria fix.
We think there's a very good chance that other folks will see build time improvements too. If you're using Webpack 5, maybe give it a go.