Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Making callSiteLocation more robust #48

Open
wants to merge 4 commits into
base: master
Choose a base branch
from

Conversation

Lucas-C
Copy link

@Lucas-C Lucas-C commented Mar 15, 2022

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 dougwilson closed this Mar 15, 2022
@dougwilson dougwilson reopened this Mar 15, 2022
@dougwilson
Copy link
Owner

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
Copy link
Owner

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
Copy link
Author

Lucas-C commented Mar 15, 2022

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
Copy link
Owner

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

@dougwilson
Copy link
Owner

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
Copy link
Author

Lucas-C commented Mar 15, 2022

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
Copy link
Owner

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
Copy link
Author

Lucas-C commented Mar 15, 2022

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
Copy link
Owner

dougwilson commented Mar 15, 2022

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
Copy link
Author

Lucas-C commented Mar 15, 2022

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
Copy link
Author

Lucas-C commented Mar 15, 2022

@dougwilson
Copy link
Owner

dougwilson commented Mar 15, 2022

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
Copy link
Author

Lucas-C commented Mar 16, 2022

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 Lucas-C closed this Mar 16, 2022
@Lucas-C Lucas-C reopened this Mar 16, 2022
@Lucas-C
Copy link
Author

Lucas-C commented Mar 16, 2022

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
Copy link
Owner

dougwilson commented Mar 16, 2022

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
Copy link
Owner

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

@dougwilson
Copy link
Owner

dougwilson commented Mar 16, 2022

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
Copy link
Author

Lucas-C commented Mar 16, 2022

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
Copy link
Owner

dougwilson commented Mar 16, 2022

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 👍

index.js Outdated Show resolved Hide resolved
@Lucas-C
Copy link
Author

Lucas-C commented Mar 16, 2022

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
Copy link
Owner

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
Copy link
Author

Lucas-C commented Mar 16, 2022

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

index.js Outdated Show resolved Hide resolved
@dougwilson
Copy link
Owner

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
Copy link
Owner

dougwilson commented Mar 16, 2022

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 dougwilson closed this Mar 16, 2022
@dougwilson
Copy link
Owner

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
Copy link
Author

Lucas-C commented Mar 16, 2022

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
Copy link
Owner

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
Copy link
Author

Lucas-C commented Mar 16, 2022

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
Copy link
Owner

dougwilson commented Mar 16, 2022

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.

@dougwilson dougwilson reopened this Mar 16, 2022
@Lucas-C Lucas-C force-pushed the master branch 3 times, most recently from 38e16c7 to f7cfaa5 Compare March 18, 2022 13:15
@Lucas-C Lucas-C force-pushed the master branch 5 times, most recently from 265f344 to b4de4bf Compare March 18, 2022 13:40
@Lucas-C
Copy link
Author

Lucas-C commented Mar 18, 2022

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
Copy link
Owner

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 zloirock/core-js#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
Copy link
Author

Lucas-C commented Mar 18, 2022

I also tried another approach here: sncf-connect-tech@852f04f (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
Copy link
Author

Lucas-C commented Mar 18, 2022

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.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

Successfully merging this pull request may close these issues.

None yet

2 participants