iconv-lite
iconv-lite copied to clipboard
ashtuchkin
Stumped on error with requiring ../encodings
I've been stumped by this error a few times, and it's really hard to reproduce because it only happens once on a new install. So in a desperate attempt to glean more information, I'm posting this here to see if someone with a bit more knowledge can help point me in the right direction.
This error seems to be something with iconv-lite failing to require ../encodings but it does exist. What's even more strange is that if you restart the server it works fine thereafter.
Here is the stacktrace of the error:
15:40:48 err! [console] Error: Cannot find module '../encodings'
at Function.Module._resolveFilename (module.js:326:15)
at Function.Module._load (module.js:277:25)
at Module.require (module.js:354:17)
at require (internal/module.js:12:17)
at Object.getCodec (/somepath/node_modules/body-parser/node_modules/iconv-lite/lib/index.js:61:27)
at Object.getDecoder (/somepath/node_modules/body-parser/node_modules/iconv-lite/lib/index.js:118:23)
at getDecoder (/somepath/node_modules/body-parser/node_modules/raw-body/index.js:44:18)
at readStream (/somepath/node_modules/body-parser/node_modules/raw-body/index.js:218:15)
at getRawBody (/somepath/node_modules/body-parser/node_modules/raw-body/index.js:106:12)
at read (/somepath/node_modules/body-parser/lib/read.js:76:3)
at jsonParser (/somepath/node_modules/body-parser/lib/types/json.js:121:5)
at Layer.handle [as handle_request] (/somepath/node_modules/express/lib/router/layer.js:95:5)
at trim_prefix (/somepath/node_modules/express/lib/router/index.js:312:13)
at /somepath/node_modules/express/lib/router/index.js:280:7
at Function.process_params (/somepath/node_modules/express/lib/router/index.js:330:12)
at next (/somepath/node_modules/express/lib/router/index.js:271:10)
at expressInit (/somepath/node_modules/express/lib/middleware/init.js:33:5)
at Layer.handle [as handle_request] (/somepath/node_modules/express/lib/router/layer.js:95:5)
at trim_prefix (/somepath/node_modules/express/lib/router/index.js:312:13)
at /somepath/node_modules/express/lib/router/index.js:280:7
at Function.process_params (/somepath/node_modules/express/lib/router/index.js:330:12)
at next (/somepath/node_modules/express/lib/router/index.js:271:10)
at query (/somepath/node_modules/express/lib/middleware/query.js:49:5)
at Layer.handle [as handle_request] (/somepath/node_modules/express/lib/router/layer.js:95:5)
at trim_prefix (/somepath/node_modules/express/lib/router/index.js:312:13)
at /somepath/node_modules/express/lib/router/index.js:280:7
at Function.process_params (/somepath/node_modules/express/lib/router/index.js:330:12)
at next (/somepath/node_modules/express/lib/router/index.js:271:10)
at Function.handle (/somepath/node_modules/express/lib/router/index.js:176:3)
at EventEmitter.handle (/somepath/node_modules/express/lib/application.js:173:10)
at Server.app (/somepath/node_modules/express/lib/express.js:38:9)
at Server.<anonymous> (/somepath/node_modules/socket.io/node_modules/engine.io/lib/server.js:434:22)
at Server.<anonymous> (/somepath/node_modules/socket.io/lib/index.js:260:16)
at emitTwo (events.js:87:13)
at Server.emit (events.js:172:7)
at HTTPParser.parserOnIncoming [as onIncoming] (_http_server.js:528:12)
at HTTPParser.parserOnHeadersComplete (_http_common.js:88:23)
EventEmitter.logerror [console] (application.js:629)
at Console.error (/somepath/baymax.bundle.js:160:3265)
at EventEmitter.logerror (/somepath/node_modules/express/lib/application.js:629:43)
at Immediate.immediate._onImmediate (timers.js:445:18)
at processImmediate [as _immediateCallback] (timers.js:383:17)
I just encountered this in an expressjs application after upgrading from node 4.2 to 6.6.0. After upgrading node, I removed my node_modules folder and ran a fresh 'npm install'. First startup seemed healthy until posting a form to the server where I saw this issue. As mentioned by @leanderlee restarting the service seemed to fix it.
Still cannot reproduce it :( Tried the upgrade method you described and it worked without any errors..
Let me know if you're able to consistently reproduce it.
Issue is due to changing the current working directory of node.js process after process starts and then you attempt to perform method using iconv-lite. The lazy require breaks since it's no longer in the same relative path. Same if node_modules somehow disappears after process start.
I think I found the solution.
Try changing:
iconv.encodings = require("../encodings");
to
iconv.encodings = require("iconv-lite/encodings");
https://github.com/ashtuchkin/iconv-lite/blob/master/lib/index.js#L61
I can reliably recreate this error in our test environment, we deploy node and mode_module updates packaged into an rpm, and in our latest version, our code is crashing on body parsing due to its use of this library. restarting our node service fixes this issue, it only happens right after we deploy the rpm.
Guys I need your help here. I don't have an environment to reproduce it, so I'm counting on you to isolate the exact requirements for this to happen.
I'm also not fond of changing that line to iconv.encodings = require("iconv-lite/encodings"); because that is a workaround for require() bug - it should be fixed on their side. By specification, require should work relative to the caller .js file and it's a much larger issue if it doesn't.
@ashtuchkin -
This isn't something which requires you setup a reproducible environment to isolate or fix the bug.
It seems to be simple. Looking at https://github.com/ashtuchkin/iconv-lite/blob/master/lib/index.js#L61 , we can see that we have a "lazy require" statement.
In other words, we have a require statement which isn't being executed until getCodec function is executed. This is not a bug in require(). There are many reasons and conditions which could cause a lazy require statement to fail.
In the case I hit ( a production service serving millions of requests ), the Node.js process was being chroot to a new directory after the process started. This means that the relative path of ../encodings is no longer valid, hence the errors. Generally, it's not safe to do a lazy require of modules.
Is there a reason that ../encodings.js file is being loaded lazily in getCodec? Could it be required outside the function scope?
Also, you could probably replicate the bug using https://www.npmjs.com/package/chroot library.
Thanks for the extended explanation, @Marak.
Generally, it's not safe to do a lazy require of modules.
It looks to me that generally, it's not safe to do a chroot of a node process, because node's module caching has unexpected results for dynamic requires. Are you sure other libraries/modules don't use it? It's a perfectly valid mode of loading modules in node.js, as far as I know.
Is there a reason that ../encodings.js file is being loaded lazily in getCodec?
Yes, it's an explicit optimization of startup time. Encodings tree is large and can take several hundred ms to load. I don't want to impose this tax on all projects indirectly requiring iconv-lite because they might not use (or even know about) it at all.
I still don't know why it works the second time for @dbussert - module caching should not depend on that.
@ashtuchkin -
Lazy loading of Node.js modules is not a best practice and can cause several issues. You should understand that require is a synchronous and blocking statement. The same 100ms you are saving on initial load time will now be 100ms of blocked process time when getCodec is first called. I could go on and on. I won't. You are wrong, sorry.
Regardless, I understand the need for optimization on start time. It's a trade-off you have to make. Based on what I see here, the majority of users will never experience this require failing issue and will benefit from the optimized start time. HOWEVER, some users are experiencing this issue and I'm telling you exactly why it's happening.
You should either figure out a fix, or tell us you will not fix it. I already proposed the solution we used in production. What none of us need here is reasons why you don't think this is broken.
Cheers.
Dear @Marak,
I'm yet to find evidence that others are experiencing the same issue as you are. All the other people in this thread have a situation where a restart "fixes" the problem, which should not happen with a chroot. Also I haven't seen any mention of chroot other than from you. So, I'm still gathering information about that case and would prefer you stop interfering and going personal about it. There's no need to preach about best practices, tell me what I should do, or talk like you represent all the other people in this thread.
As for your particular problem - no, I won't fix it for you. The core reason you have this problem is you built a system based on a subtly incorrect assumption that the node module system works correctly after a chroot. This subtle incorrectness showed itself when you started using iconv-lite, but it has potential to show for other modules as well. You cannot assume that other modules won't use a valid system interface because you think it's "not a best practice". I'm glad you found a workaround for your particular system, but 1) it's not guaranteed to work for other people, and 2) you'll need to find similar workarounds for other libraries/modules. I would've recommended to stop relying on the assumption above and try to fix your system in a more general way, like using a separate process to do the chroot and only start your original node process after that, but I don't have enough context about your system.
To be clear, I'm not being stubborn about making the change you suggested. I'm not doing that because:
- As I said earlier, I don't have evidence that this what's actually happening for the OP and other people in this thread.
- Each part of the current solution is there for a good reason:
- Dynamic require provides the dont-pay-if-you-dont-use guarantee for users with regards to startup time, as we discussed previously.
- Relative require path guarantees that I'm requiring file from the same exact module. As you might already know, there can be several versions of a module installed in a node_modules folder and I have no idea which one of them will be resolved to a top-level 'iconv-lite'. I hope I don't have to explain why this requirement is important.
Have you considered what is going to happen if someone is running a webserver with 1000s of requests per second and then getCodec method is called for the first time? I believe all requests will block until encodings file completes load.
I hit this problem ( of not being able to find encodings file ), found the solution, and posted it here. You want to lazy require a huge file with a relative path, go for it. Every-time anyone hits any environment issue with express where node_modules is not where it's suppose to be after process start is going to google and find this Github Issue. It's why you are seeing a variety of issues reported here with seemingly different sources and behaviors...
The lazy loading also seems to be causing an issue in other libraries... https://github.com/facebook/jest/issues/2605
I got the same problem as @Marak is describing, and it does not solve if I restart. His fix worked for me. And I agree with @Marak. Instead of excusing this behaviour, treat it as the bug it is and fix, please.
I'm experiencing the same issue when executing a script within my sandboxed test environment (Jest) which uses iconv-lite as a dependency.
When I'm not lazy-loading encodings/index.js (but instead requiring everything directory at the top of the module) everything works fine for me.
The initial reason for lazy-loading this module was because of speed issues, which were fixed in PR https://github.com/ashtuchkin/iconv-lite/pull/26.
I ran this script twice (both using lazy-loading and without) and got the following results:
With lazy-loading:
❯ node -e "require('./lib/index')" 0.18s user 0.02s system 98% cpu 0.204 total
Without lazy-loading (changed iconv.encodings = require('../encodings') at the top of the file):
❯ node -e "require('./lib/index')" 0.18s user 0.02s system 98% cpu 0.204 total
The results seem to be exactly the same. I'm not sure if something changed within Node itself, or if I'm doing something wrong, but if this those stats are correct there would be no reason to lazy-load the encodings anyway.
Still experiencing this problem. I am running inside a Docker environment.
Running npm install again and then restarting the app fixed the problem for me.
Facing this issue with Electron and the asar package format, used the patch-package package to disable lazy-loading, and everything is now working.
@octalmage there are several different problems discussed in this issue, could you provide more info about your setup to help me understand what's happening? Thanks!
@ashtuchkin -
I've been reviewing this thread again since it popped up in my feed.
Re-reading my old posts I can see the language and tone I was using wasn't the best for collaboration.
If you'd like to get this issue closed I believe all the information needed is here posted above with my comments and other user's comments.
I would consider removing the lazy loading entirely or make it a configurable option which is disabled by default.
This issue happens whenever I try to POST JSON data to the server. It's in chroot jail, but removing that does not fix it. Nor does reinstalling node_modules or restarting the server. Express goes to decode the payload and fails to lazy load the encoding module. This issue has been open for four years - time to actually fix it?
It's worth mentioning that I use node 12.18.0, express 4.16.2 and body-parser 1.18.3 all in Docker, everything was fine until the 18th December 2020 when upgrading Docker Desktop from 3.01 to 3.0.2 I started seeing this error:
api_1 | Error: Cannot find module '../encodings'
api_1 | Require stack:
api_1 | - /usr/src/app/node_modules/iconv-lite/lib/index.js
api_1 | - /usr/src/app/node_modules/raw-body/index.js
api_1 | - /usr/src/app/node_modules/body-parser/lib/read.js
api_1 | - /usr/src/app/node_modules/body-parser/lib/types/json.js
api_1 | - /usr/src/app/node_modules/body-parser/index.js
api_1 | - /usr/src/app/node_modules/express/lib/express.js
api_1 | - /usr/src/app/node_modules/express/index.js
api_1 | - /usr/src/app/server.js
...
Rolling back to 3.0.1 fixed the issue but means I'm unable to update Docker for now.
Thanks for your report! Could you add a bit more details into your setup?
Are you running your code from a mounted folder? Do you unmount it yourself after it starts? Could you check if it's being unmounted by docker itself?
The exception only occurs if node process doesn't have access to node_modules some time after starting, so I'm trying to understand what exactly happens.
I don't see anything relevant in docker release notes https://docs.docker.com/docker-for-mac/release-notes/#docker-desktop-community-302
Alex
On Mon, Dec 21, 2020, 11:32 Paul Gain [email protected] wrote:
It's worth mentioning that I use node 12.18.0, express 4.16.2 and body-parser 1.18.3 all in docker, everything was fine until the 18th December 2020 when upgrading docker desktop from 3.01 to 3.0.2 I started seeing this error:
api_1 | Error: Cannot find module '../encodings' api_1 | Require stack: api_1 | - /usr/src/app/node_modules/iconv-lite/lib/index.js api_1 | - /usr/src/app/node_modules/raw-body/index.js api_1 | - /usr/src/app/node_modules/body-parser/lib/read.js api_1 | - /usr/src/app/node_modules/body-parser/lib/types/json.js api_1 | - /usr/src/app/node_modules/body-parser/index.js api_1 | - /usr/src/app/node_modules/express/lib/express.js api_1 | - /usr/src/app/node_modules/express/index.js api_1 | - /usr/src/app/server.js ...
Rolling back to 3.0.1 fixed the issue but means I'm unable to update docker for now.
— You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub https://github.com/ashtuchkin/iconv-lite/issues/118#issuecomment-749063597, or unsubscribe https://github.com/notifications/unsubscribe-auth/AAEZKHNCWZ6L76S2TQ2SLNLSV52A7ANCNFSM4CBCI3HA .
@ashtuchkin I encountered the exact same problem you mentioned in your initial error. I am running a Node server on a Xenial VM on GCP and after running my app.js and making a POST request to send an email, it makes use of iconv-lite at some point and throws cannot find module '..encodings/'. Like one of the suggestions I ran npm install on the VM and it worked. But that defeats the purpose of a pipeline which is actually how I'm deploying my application. So is there any fix for this yet? Or do i have to add another npm install after deploying it.. which is a very inconvenient solution.
@MeanManMachineMan can you provide more details about how you're deploying your app.js? Do you bundle it somehow? I'm trying to understand whether the encodings/ directory disappears after you're starting the app or it just never getting shipped to the VM.
As a stop-gap, you can always manually require the module from your exception in your app, so that it's in the cache instead of loading on-demand.
@ashtuchkin Yes certainly. I don't bundle my app.js since it's not a very big file and it just needs to act as a server for a few features. I simply serve it with pm2 start app.js. you can always manually require the module from your exception in your app Could you please elaborate on this?
You mentioned it works if you run npm install on the VM, so you usually don't do it, right? How do you get node_modules directory on the VM in the first place?
Could you please elaborate on this?
// If you import iconv-lite like this:
const iconv = require('iconv-lite');
// Then add this line right below to preload encodings:
iconv.encode("", "utf8"); // or whatever encoding you use.
// alternatively, you can use this:
require("iconv-lite/encodings");
Ah I can see why the confusion has risen haha. I meant to say @dbussert had said that reinstalling it works. So after I have deployed the application through my pipeline (which runs npm install once and gets the node server up and running), I ssh into the vm, navigate to the app folder and run npm install once again and that seems to fix it. Oh but I don't use iconv-lite directly. It's getting called by body-parser :/
yep that's what I'm trying to get to - how is your pipeline transferring the contents of node_modules to the vm so that it apparently loses some of the files (which you add back by doing npm install)? Is this some GCP-provided thing you're using or is it your own script? Also could you maybe attach result of ls -alR node_modules command before and after you do 'npm install' on your VM, so that I can see what changes to make it work?
As for body-parser - I believe you can access its version of iconv-lite using iconv = require("body-parser/node_modules/iconv-lite") and then use the code above.
My pipeline isn't "transferring" any contents because in my repository I don't have any node_modules folder, only the package.json file. I'm using a gitlab runner for my CI pipeline, if that's what you're trying to find out. I run npm install for the first time on the VM which creates the node_modules folder inside my folder containing app.js, but then in pm2's logs I see that while POSTing some JSON data to an API running on my app.js server, it throws the module not found error. So I just run npm install again and it works like a charm. Hmm, upon navigating to my node_modules/body_parser directory in my app.js folder, there doesn't seem to be any node_modules inside body-parser, wouldn't that make my require(...) fail? Btw here is the dump of the error that my app.js returns upon making the API call after running npm install for the first time:
Error: Cannot find module '../encodings'
Require stack:
- /home/gitlab-runner/builds/BxePFZSb/0/some_name/some_name/api/node_modules/iconv-lite/lib/index.js
- /home/gitlab-runner/builds/BxePFZSb/0/some_name/some_name/api/node_modules/raw-body/index.js
- /home/gitlab-runner/builds/BxePFZSb/0/some_name/some_name/api/node_modules/body-parser/lib/read.js
- /home/gitlab-runner/builds/BxePFZSb/0/some_name/some_name/api/node_modules/body-parser/lib/types/json.js
- /home/gitlab-runner/builds/BxePFZSb/0/some_name/some_name/api/node_modules/body-parser/index.js
- /home/gitlab-runner/builds/BxePFZSb/0/some_name/some_name/api/node_modules/express/lib/express.js
- /home/gitlab-runner/builds/BxePFZSb/0/some_name/some_name/api/node_modules/express/index.js
- /home/gitlab-runner/builds/BxePFZSb/0/some_name/some_name/api/app.js
at Function.Module._resolveFilename (node:internal/modules/cjs/loader:924:15)
at Module.Hook._require.Module.require (/usr/lib/node_modules/pm2/node_modules/require-in-the-middle/index.js:61:29)
at require (node:internal/modules/cjs/helpers:92:18)
at Object.getCodec (/home/gitlab-runner/builds/BxePFZSb/0/some_name/some_name/api/node_modules/iconv-lite/lib/index.js:65:27)
at Object.getDecoder (/home/gitlab-runner/builds/BxePFZSb/0/some_name/some_name/api/node_modules/iconv-lite/lib/index.js:127:23)
at getDecoder (/home/gitlab-runner/builds/BxePFZSb/0/some_name/some_name/api/node_modules/raw-body/index.js:45:18)
at readStream (/home/gitlab-runner/builds/BxePFZSb/0/some_name/some_name/api/node_modules/raw-body/index.js:180:15)
at getRawBody (/home/gitlab-runner/builds/BxePFZSb/0/some_name/some_name/api/node_modules/raw-body/index.js:108:12)
at read (/home/gitlab-runner/builds/BxePFZSb/0/some_name/some_name/api/node_modules/body-parser/lib/read.js:77:3)
at jsonParser (/home/gitlab-runner/builds/BxePFZSb/0/some_name/some_name/api/node_modules/body-parser/lib/types/json.js:135:5)
@ashtuchkin I actually figured out why I was getting that error dump. When I logged into the VM in my api directory I saw no node_modules folder. But since I was using express in my app and node wasn't complaining about express not being found, I assumed it was finding express somewhere and I didn't worry about it. But now I remembered that on sunday I ssh'd into the VM and ran npm install -g express which installed it in /usr/lib/node_modules.... So for running app.js and serving a default / route, it didn't throw any errors. But since iconv-lite uses lazy-loading to call encodings, I saw the error only when I was using the function stub that called body-parser (please correct me if my understanding of this is wrong), i.e my POST route. Now this error was actually thrown because I didn't have a node-modules folder in my app.js director because of the gitlab_runner jobs. So what happens when you define multiple jobs in your yaml file is that the work of one job is deleted by the subsequent job and so on, and i was absolutely in the dark about this fact and so I couldn't figure out for the life of me why node couldn't even find express initially(which is why i went ahead and did a global install of express just for the heck of it without really understanding why it wasn't working). So now after I put all my npm install statements of my react and node application into the same job, it goes and works like a charm. So to summarize, if you have multiple npm install statements required for your application, keep them in the same job or else the node_modules of the previous job will be overwritten and it will throw all sorts of module not found errors.
Thanks for digging through it @MeanManMachineMan! It's becoming much clearer now. Basically node_modules directory was being cleaned up by a different task while the test was running, right? That would definitely result in this error. Let me know if you need anything else.
@ashtuchkin Yes, you are correct! I do have another question through, why didn't app.js complain about body-parser not being found(since node_modules didn't exist) before jumping straight to ../encodings? Is it because I had explicitly require(..)'d body-parser in my app so it was somehow getting loaded into some sort of local context(I don't know if that's the right word for it)? I'm a bit hazy about that part and I'd be glad if you could shed some light on that for me.
When you run app.js, first thing it does is it loads all the required modules in memory. For most apps it means that you can delete node_modules directory after your process has started and it will work just fine.
Iconv-lite is an outlier in this regard as it can take from 20 to 150ms to load all the character tables (especially chinese, japanese encodings). This translates directly to startup time of any app that uses e.g. express framework. As encoding conversion is not actually needed for 99.99% apps, it makes sense to lazy-load character tables so that you pay this latency penalty only if you actually need them. If at that point node_modules folder is not present, then that error happens.
Aha that clears it up pretty much. Thanks for taking out your time to help me @ashtuchkin!