Spelunking in node_modules 👷

Photo by Colin Rex on Unsplash

Deep dive into Jest, React, and jsdom: A story about how I go about finding and fixing bugs in my dependencies.

This last week I started work again after over a month away. What's the first thing you do when you get back from that long away? Why, upgrade dependencies of course! In particular, this was for my kcd-scripts and paypal-scripts projects. Of note, Rollup, Jest, and lint-staged each received a few nice additions so I was excited to get things going!

For the most part, things went over smoothly. I had a few deprecation warnings with rollup that were simple enough. There was a simple change I needed to make for changes in Jest (which I think I'll be able to revert when this is released).

But then I started updating kcd-scripts in several of my projects. Things were going great until I updated downshift . I not only updated kcd-scripts , but also react , and that's when the trouble started. downshift has several tests for error cases (errors thrown when validating how you interact with the prop getters for example). It has some assertions that an error is thrown when doing something wrong when trying to mount downshift. This test in particular resulted in this output:

1 Error: Uncaught [Error: downshift: You provided the id of "foo" for your input, but the htmlFor of your label is "bar". You must either remove the id from your input or set the htmlFor of the label equal to the input id.] 2 at reportException (/Users/kdodds/Developer/downshift/node_modules/jsdom/lib/jsdom/living/helpers/runtime-script-errors.js:66:24) 3 at invokeEventListeners (/Users/kdodds/Developer/downshift/node_modules/jsdom/lib/jsdom/living/events/EventTarget-impl.js:209:9) 4 at HTMLUnknownElementImpl._dispatch (/Users/kdodds/Developer/downshift/node_modules/jsdom/lib/jsdom/living/events/EventTarget-impl.js:119:9) 5 at HTMLUnknownElementImpl.dispatchEvent (/Users/kdodds/Developer/downshift/node_modules/jsdom/lib/jsdom/living/events/EventTarget-impl.js:82:17) 6 at HTMLUnknownElementImpl.dispatchEvent (/Users/kdodds/Developer/downshift/node_modules/jsdom/lib/jsdom/living/nodes/HTMLElement-impl.js:30:27) 7 at HTMLUnknownElement.dispatchEvent (/Users/kdodds/Developer/downshift/node_modules/jsdom/lib/jsdom/living/generated/EventTarget.js:143:21) 8 at Object.invokeGuardedCallbackDev (/Users/kdodds/Developer/downshift/node_modules/react-dom/cjs/react-dom.development.js:581:16) 9 at invokeGuardedCallback (/Users/kdodds/Developer/downshift/node_modules/react-dom/cjs/react-dom.development.js:438:27) 10 at renderRoot (/Users/kdodds/Developer/downshift/node_modules/react-dom/cjs/react-dom.development.js:10366:7) 11 12 ...

I clipped the output, see > this gist > for the full output.

The funny thing about this though is that the tests all still passed! In addition, those logs are coming from a console.error call, and the top of that file is mocking console.error to make it not log anything at all!

1 beforeEach ( ( ) => { 2 jest . spyOn ( console , 'error' ) 3 console . error . mockImplementation ( ( ) => { } ) 4 } ) 5 6 afterEach ( ( ) => { 7 console . error . mockRestore ( ) 8 } )

This is how we avoided the noise from React logging the error (which we were expecting) in the first place! Oh, and the error isn't coming from React... Not directly anyway... It's actually coming from JSDOM! Remember that stack trace? The top of it says:

1 at reportException (/Users/kdodds/Developer/downshift/node_modules/jsdom/lib/jsdom/living/helpers/runtime-script-errors.js:66:24)

What do you do when confronted with a stack trace?

When you see a stack trace like this, you first see where things are going wrong in your own code. That might help you know what's going on in your own code to cause the issue and you can fix it. If you can't figure it out from there, then it can be really helpful to follow the stack trace as much as you can. Stepping through a debugger (in browser DevTools for example) is a fantastic way to do this.

So here's where we get spelunking. I knew that my code was fine because it worked properly before I upgraded my dependencies. So I figured that something must have changed in my dependencies. So what do we do? Whelp, crack open the old node_modules directory and see what's up!

Did you know that node_modules directories are mostly full of JavaScript files? Check this out. Run the following commands and you'll get a report of the code on the node_modules directory in the downshift project:

1 git clone https://github.com/downshift-js/downshift.git 2 cd downshift 3 npm install 4 npx cloc ./node_modules

That'll take a fair amount of time, so I'll save you the trouble:

1 ... 2 ------------------------------------------------ 3 Language files blank comment code 4 ------------------------------------------------ 5 JavaScript 21024 283714 342123 1735415 6 JSON 2807 1422 0 550205 7 Markdown 1736 66030 4 168463 8 TypeScript 1032 17525 56659 127105 9 HTML 60 2463 40 20773 10 XML 45 241 13 9377 11 C/C++ Header 20 1115 325 5571 12 ...

I clipped the output because it's so big. > See this gist for the full output of the last command.

Wow! Look at all that JavaScript (1.7 MILLION lines of code (excludes blank lines and comments)... note: this has kcd-scripts which has some heavy deps but WOW)! And guess what! You can open it up in your editor and make changes to it! Then you can run your scripts again and they'll pick up your changes! How cool is that!?

So that's what I did. I jumped into the code and came out with this (spoiler alert): Jest issue #5223: "jsdom console is unmockable".

Here's a TL;DR on the issue:

Ok, so far so good (hopefully... Stay with me now! Or just skip to the end for the takeaways). But why in heaven's name is my mocking of the console not mocking the console that VirtualConsole is using?!

So here's what I did. I noticed that it was using anyConsole.error instead of console.error . anyConsole is passed into the function where this code lives. I verified that sendTo is passed console . Then, to be doubly sure, I changed this line to this (added the console.log ):

1 this . on ( 'jsdomError' , e => { 2 console . log ( anyConsole === console ) 3 anyConsole . error ( e . stack , e . detail ) 4 } )

Then I ran my tests. I was only partially surprised when that returned true . On the one hand that made sense because that's what's passed into the sendTo function, but on the other, it wasn't behaving like the console in my test file. So I added this line to the top of my test file:

1 global . MY_CONSOLE = console

And then changed the code again to this:

1 this . on ( 'jsdomError' , e => { 2 console . log ( anyConsole === global . MY_CONSOLE ) 3 anyConsole . error ( e . stack , e . detail ) 4 } )

And poof! I was getting false ! So somehow the console I was getting in my test file was NOT the same as the normal console. I actually already knew this because Jest does some cool magic to make your console logs more helpful (like showing the file and line where the log is coming from in your code). But somehow that fake console that Jest provides your tests doesn't make its way to JSDOM.

Whelp, to make a long story less long, I found where jest creates its fake console and as it turns out that's also where Jest runs your code in its own environment so it's isolated from other tests. That means it gets its own global and hence its own console .

Phew 😌

So my fix included moving the creation of the testConsole to before JSDOM was initialized in jest-environment-jsdom and passing the testConsole to jest-environment-jsdom so it could create our own instance of VirtualConsole that used the given testConsole . When I got that working in my node_modules , I made a pull request for the changes (I even live streamed me making it 📺), we iterated on it (I live streamed some of that too 📺), and it eventually got merged! 🎉

Key Takeaways

So, this story was a little technical and I got into the nitty gritty details of three huge projects (JSDOM, Jest, and React). And that's my first takeaway!

Learn about how your dependencies work

It's an amazing learning experience! Not only do I know more about how the dependencies work, but that knowledge could provide an opportunity for me to apply my learning to other problems.

node_modules is a TON of JavaScript

And that's a language that you're writing your code in too. And it's code you can modify and play around with. Add console.log s (and throw new Error(JSON.stringify({foo: 'bar'}, null, 2)) ) in a few places to make sure that code is reaching where you think it is and learn how the code flows through your dependencies. That will help you come up with how the problem can be solved and help you know what you can do to contribute to a solution in a pull request.

Solve (y)our own problems

I could have just reported my issue and reverted my upgrade and waited for someone else to solve my problem. Would have been easy. But then I wouldn't have been able to get the sweet new features I was looking forward to in Jest 22 (like that codeframe 😍)! On top of that, when you npm install something, you become responsible for that project. We're all maintainers of the projects we use.

I hope this is helpful! Good luck!👍