dougwilson / nodejs-depd

Deprecate all the things
MIT License
325 stars 87 forks source link

Making callSiteLocation more robust #48

Open Lucas-C opened 2 years ago

Lucas-C commented 2 years ago

Hi

We had several issues when using the body-parser lib, that itself uses depd, under NodeJS 5:

TypeError: callSite.getFileName is not a function
    at callSiteLocation (C:\nodejs-depd-bug-repro\dist\bundle.js:452:3231)
    at depd (C:\nodejs-depd-bug-repro\dist\bundle.js:452:1375)
    at node_modulesBodyParserIndexJs (C:\nodejs-depd-bug-repro\dist\bundle.js:508:172)
    at __require (C:\nodejs-depd-bug-repro\dist\bundle.js:1:8616)
    at Object.<anonymous> (C:\nodejs-depd-bug-repro\dist\bundle.js:509:68)

This patch makes sure that callSiteLocation never crashes, even when some underlying methods do not exist or its callSite argument does not have the expected object type (it was String in some cases we investigated).

dougwilson commented 2 years ago

Can you add a test for the environment where it is a string or provide a reproducable test case? As far as I know, that API from v8 cannot return a string, so perhaps there is something very wrong in the environment. I can add support for more environments, but need to add tests and understand the environment so it can be supported.

I won't just merge this without that.

dougwilson commented 2 years ago

I tried Node.js 5 manually, and there is 5.12 as part of the CI run and everything works. It could be the specific version of NodeJS 5 if you happen to know I can try it.

Lucas-C commented 2 years ago

Ok, I'm trying to investigate a bit further...

So far I found out that getStack() returns the string rror because obj.stack is the string Error

$ node --version
v5.12.0

Note that I'm under Windows

This seems to match what I see: https://stackoverflow.com/a/67073333/636849

dougwilson commented 2 years ago

I am also on and testing in Windows, and the CI tests 5.12.0 also in Windows via AppVeyor...

dougwilson commented 2 years ago

Also in case you are curious, this is the docs for the Error object stack trace API: https://v8.dev/docs/stack-trace-api It's been unchanged since Node.js's inception (v8 has just had it before Node.js existed). Essentially there are two parts you can see in getStack: Error.prepareStackTrace is set up to return the structured object and Error.captureStackTrace will populate said object into the error property of obj. That structured object has all the .get*() methods on it.

It does seem weird if it is not working as v8 documents; I wonder what the cause / environment would be. Maybe a custom-compiled Node.js you are using?

Lucas-C commented 2 years ago

After re-reading your code and the documentation on Error.captureStackTrace, it seems to be that obj.stack is expected to be a string.

I don't quite understand why in your lib code getStack() is supposed to return an array.

dougwilson commented 2 years ago

Yes, that is the default behavior of Error.captureStackTrace, but you can change the behavior using Error.prepareStackTrace, which is what this module is doing.

Lucas-C commented 2 years ago

OK, thanks for the explanation.

I think 2 libs are conflicting in my case: https://github.com/felixge/node-stack-trace/blob/v0.0.10/lib/stack-trace.js#L8

dougwilson commented 2 years ago

Interesting. It shouldn't, since you see it sets Error.prepareStackTrace, calls Error.captureStackTrace and then restores it back, which is the same thing this module does. I just simply added that module real quick to the test suite of this module and it didn't seem to change the behavior. How are you using it? Could you make like a little file that uses the two libs that shows the conflict happening?

Edit: The Error.prepareStackTrace that lib uses is identical (except for variable names) as this lib uses, so it would work just fine anyhow.

Lucas-C commented 2 years ago

You are right, this was a red herring

I found just out that my bundle also integrates some Error-related polyfills from core-js. I have to pause investigating for today, but I'll add updates here once I find more. Thanks for your help!

Lucas-C commented 2 years ago

This is definitively an issue with this polyfill: https://github.com/zloirock/core-js/blob/master/packages/core-js/internals/wrap-error-constructor-with-cause.js

dougwilson commented 2 years ago

Interesting. There is definitely a lot going on in there and honestly I am not very familiar with core-js 😂 . Do you think you can put together a simple like file that combines that core-js stuff that reproduces the error? I can help take a look / even help make any appropriate tests if needed. Looking at the code, the bulk of it only runs with "FORCED" is true, which sounds like something has to "force" core-js to do whatever the wrapper stuff is (assuming that is where the conflict is coming from). It does seem like such a polyfill should be unnecessary for Node.js 5.12.0, though (besides the part above the "FORCED" which adds cause).

Lucas-C commented 2 years ago

There is some minimal project that reproduces the bug I'm facing: https://github.com/voyages-sncf-technologies/nodejs-depd-bug-repro

(I misclicked and closed this by error - reopening now)

Lucas-C commented 2 years ago

I think a better fix than this PR could be to ensure that in getStack(), obj.stack is an array of CallSite objects, and if is not (e.g. it's a string, as in my case), use a safe fallback that could be parsed by callSiteLocation().

Also, I tried to make Error.prepareStackTrace work when core-js polyfill is enabled, but failed to do so so far.

Maybe you could also try to simply use an existing lib to do the job, like https://github.com/felixge/node-stack-trace

dougwilson commented 2 years ago

I think a better fix than this PR could be to ensure that in getStack(), obj.stack is an array of CallSite objects, and if is not (e.g. it's a string, as in my case), use a safe fallback that could be parsed by callSiteLocation().

That sounds fine. I am happy to accept a PR that would do so 😊

Maybe you could also try to simply use an existing lib to do the job, like https://github.com/felixge/node-stack-trace

A goal of this module is to have zero dependencies. In addition, the parsing of stack traces in there does not work correctly in Node.js, only the web browser, unfortunately. For example, file names can include a newline character unlike a web page address, which you break the string parsing of the stack that module does when done in Node.js.

dougwilson commented 2 years ago

P.S. thanks for that repo; I will use it to help dig in to a solution as well 😀

dougwilson commented 2 years ago

Hi @Lucas-C I'm not sure if I'm missing something here, but I tried to run your repo but I couldn't even install the modules. I am using Node.js 5.12.0, as I believe that is what you said to use. Let me know if I should be using something different:

> node -v
v5.12.0
> git clone https://github.com/voyages-sncf-technologies/nodejs-depd-bug-repro.git
Cloning into 'nodejs-depd-bug-repro'...
remote: Enumerating objects: 12, done.
remote: Counting objects: 100% (12/12), done.
remote: Compressing objects: 100% (10/10), done.
remote: Total 12 (delta 2), reused 11 (delta 1), pack-reused 0
Receiving objects: 100% (12/12), 25.69 KiB | 939.00 KiB/s, done.
Resolving deltas: 100% (2/2), done.
> cd nodejs-depd-bug-repro/
> npm i

> esbuild@0.14.27 postinstall nodejs-depd-bug-repro\node_modules\esbuild
> node install.js

nodejs-depd-bug-repro\node_modules\esbuild\install.js:26
    for (let key of __getOwnPropNames(from))
         ^^^

SyntaxError: Block-scoped declarations (let, const, function, class) not yet supported outside strict mode
    at exports.runInThisContext (vm.js:53:16)
    at Module._compile (module.js:387:25)
    at Object.Module._extensions..js (module.js:422:10)
    at Module.load (module.js:357:32)
    at Function.Module._load (module.js:314:12)
    at Function.Module.runMain (module.js:447:10)
    at startup (node.js:148:18)
    at node.js:405:3

npm ERR! argv "node.exe" "npm" "i"
npm ERR! node v5.12.0
npm ERR! npm  v3.8.6
npm ERR! code ELIFECYCLE

npm ERR! esbuild@0.14.27 postinstall: `node install.js`
npm ERR! Exit status 1
npm ERR! 
npm ERR! Failed at the esbuild@0.14.27 postinstall script 'node install.js'.
npm ERR! Make sure you have the latest version of node.js and npm installed.
npm ERR! If you do, this is most likely a problem with the esbuild package,
npm ERR! not with npm itself.
npm ERR! Tell the author that this fails on your system:
npm ERR!     node install.js
npm ERR! You can get information on how to open an issue for this project with:
npm ERR!     npm bugs esbuild
npm ERR! Or if that isn't available, you can get their info via:
npm ERR!     npm owner ls esbuild
npm ERR! There is likely additional logging output above.

npm ERR! Please include the following file with any support request:
npm ERR!     nodejs-depd-bug-repro\npm-debug.log

I tried to run npm run build anyway just in case that didn't matter, but no luck, as it says esbuild is not found.

The error leads me to believe that it doesn't work with Node.js 5.12.0, though I thought that is what you said you are running. How did you get it to work / am I still supposed to be using Node.js 5.12.0 with your repo?

Edit: oh, nvm, I see now it shows in your readme you use Node.js 14 to do the build, and the run it in 5.12.

Lucas-C commented 2 years ago

I see now it shows in your readme you use Node.js 14 to do the build, and the run it in 5.12.

Exactly 😊

I updated this PR with the "improved" solution I suggested earlier

dougwilson commented 2 years ago

I updated this PR with the "improved" solution I suggested earlier

Awesome, thank you! The million-dollar question, of course, is does the solution actually work besides just not get the error. Like, do you still get the deprecation messages? Is there breakage elsewhere when other things are called? We should get the existing test suite to run in this new environment to validate the functionality of this module with these fixes 👍

Lucas-C commented 2 years ago

We should get the existing test suite to run in this new environment to validate the functionality of this module with these fixes 👍

Agreed

I could add a unit test that applies the same polyfill as core-js: do you think that would be enough?

dougwilson commented 2 years ago

I could add a unit test that applies the same mock as core-js: do you think that would be enough?

Maybe. Hard to really know until I see it, though 😂

Lucas-C commented 2 years ago

Maybe. Hard to really know until I see it, though 😂

Ok. I'll try to craft one soon, but this won't be high priority for me now, so feel free to replace this PR by some other solution you wrote yourself, with tests that match your style

dougwilson commented 2 years ago

Ok. I'll try to craft one soon, but this won't be high priority for me now, so feel free to replace this PR by some other solution you wrote yourself, with tests that match your style

NP 👍 even if you end up leaving it here (hopefully not?), this was a HUGE help! The repo itself was so helpful; and your start here is very helpful. I'll play around as well to get something landed; probably after work today or such. Have a good one!!

dougwilson commented 2 years ago

Hi 👋 so great news: this can actually be easily fixed in core-js directly! That would fix the usage of captureStackTrace, stackTraceLimit, and other APIs that are broken with the Error case wrapper, benefiting not only this module, but all others on npm that make use of the APIs in Error.

This is going to be the best way forward, because even if you just limit the scope to APIs documented on the Node.js docs, it does in fact break https://nodejs.org/dist/latest-v16.x/docs/api/errors.html#errorstacktracelimit (you'll notice in code if you write Error.stackTraceLImit = 1 stack traced are not limited to 1 when core-js is in use).

Essentially the fix is that around the part were their wrapper copies properties from the original Error to their substitute Error2, they just need to create the necessary getters/setters for Error2 to forward those get/set operations to the original Error object and everything works 🎉

Effectively just the following (added in core-js/internals/wrap-error-constructor-with-cause.js), though I'm sure it could probably be made more generic:

      Object.defineProperties(WrappedError, {
        prepareStackTrace: {
          get: function () { return OriginalError.prepareStackTrace; },
          set: function (v) { OriginalError.prepareStackTrace = v; }
        },
        stackTraceLimit: {
          get: function () { return OriginalError.stackTraceLimit; },
          set: function (v) { OriginalError.stackTraceLimit = v; }
        }
      });
dougwilson commented 2 years ago

I'll try to open a PR for core-js soon, though you are always welcome to as well if I haven't before you get a chance.

Lucas-C commented 2 years ago

I've a added one last commit with some starting point for a new test matrix entry

I see you latest comment now: great that you found a fix for core-js, good job!

dougwilson commented 2 years ago

You deserve a lot of thanks as well for putting together that repo!! I don't think they intended to break this stuff; the only reason they did was because to add the new case stuff, they had to override the actual Error constructor since you can pass in case as a constructor parameter.

Lucas-C commented 2 years ago

Note that "hardening" depd may still be a good idea: some people may have to use older versions of core-js (I think v2 is still used a lot).

And I think that the patch I suggested on index.js should have zero downside for users that don't use core-js polyfills

Plus it may be useful to have a test with core-js as part of depd test suite

dougwilson commented 2 years ago

Yea, you can open a PR that adds just a test if you want. As far as hardening, I mean if your changes actually work with all the features, sure. Unless there is a flood of users coming in to report this issue, it is likely better solved fixing upstream and letting it be vs adding additional complexity here, I think. But if you can come up with a fully working implementation, I'll land it. I can reopen this PR if you like, but with the fix being in core-js and you being the lone reporter, I probably won't work towards fixing it up in here to be honest, as I have a lot of other stuffs to work on 😀 ; so a working complete impl I can just click to land would be what I need to land something here 👍

Edit: it looks like Github actions refuses to run the PR due to invalid yaml; I tried to rerun it a few times.

Lucas-C commented 2 years ago

The tests suite won't pass because it contains many assertions like this:

    function callold () { mylib.old() }
    var stderr = captureStderr(callold)
    assert.ok(stderr.indexOf(basename(__filename)) !== -1)

But in this context, with the fix contained in this PR, the deprecation message does not include the source file: stderr is just Fri, 18 Mar 2022 13:52:36 GMT my-lib deprecated old and not Fri, 18 Mar 2022 13:52:14 GMT my-lib deprecated old at test\test.js:44:33.

The GitHub Actions pipeline is now properly running but failing in this case due to those assertions: https://github.com/voyages-sncf-technologies/nodejs-depd/actions/runs/2004432622

I don't see an easy way to fix them. Would you have any suggestion? Should all those tests be disabled if $ENABLE_COREJS_ERROR_POLYFILL is set?

dougwilson commented 2 years ago

Hi @Lucas-C thanks for the update. Yea, that was the main purpose of this module compared to others (and the deprecation stuff that is now built in to Node.js), as it's very difficult to understand where the deprecation message is coming from when a user upgrades something and their code base is dozens of files and thousands of lines. Having the stack right there definitely makes it so much easier to diagnose the code :)

As for suggestions, I'll have to take a look. Unfortunately last night I had a really bad fall and my shoulders and right arm / hand is really messed up. Got some temp splints and stuff from the Dr. but it's mainly really painful. I went and opened https://github.com/zloirock/core-js/issues/1061 this morning for you so while I'm probably going to be away from GitHub for some time, someone may be inclined to get the core-js issue fixed so you will at least have a working program again, haha.

Lucas-C commented 2 years ago

I also tried another approach here: https://github.com/voyages-sncf-technologies/nodejs-depd/commit/852f04facd29f208a52960dac62bdbbffcca23e3 (branch makeCallSite)

The pipeline is fully ✔️: https://github.com/voyages-sncf-technologies/nodejs-depd/runs/5602759731 But I had to make some minor changes to the reference test.js file, to loosen 6 assertions.

Lucas-C commented 2 years ago

Unfortunately last night I had a really bad fall and my shoulders and right arm / hand is really messed up. Got some temp splints and stuff from the Dr. but it's mainly really painful.

I'm sorry to hear that. This PR is really not important, don't bother with it. I probably got a bit obsessed with it 😅 I wish you the best with your arm. Take care.