mosh-hamedani / vidly-api-node

309 stars 285 forks source link

Node.js course - Error connecting to MongoDB in Heroku deploy #16

Open MrPaz opened 4 years ago

MrPaz commented 4 years ago

Very last video of the Node.js course, and I'm ending with an unresolved error which is frustrating. The steps for setting up a free mLab account for 500mb of storage is a bit different now (it transfers you to MongoDB Atlas, rather than doing everything in mLab now), but I think I did everything Mosh did, but am stuck, unable to connect to MongoDB. I've looked at logs and documentation for two hours and can't come up with anything, and reviewed the videos to make sure I didn't miss anything.

One portion of the log says it failed at the start script, also says failed to connect to server, and the uncaughtException.log file also says failed to connect to server connection refused. I'm not sure why this is happening. Any help would be much appreciated.

Here is my log: >heroku logs 2019-09-10T22:24:39.000000+00:00 app[api]: Build started by user randombsthrowaway@gmail.com 2019-09-10T22:25:36.350660+00:00 heroku[web.1]: State changed from crashed to starting 2019-09-10T22:25:35.910501+00:00 app[api]: Deploy 93a36670 by user randombsthrowaway@gmail.com 2019-09-10T22:25:35.910501+00:00 app[api]: Release v7 created by user randombsthrowaway@gmail.com 2019-09-10T22:25:36.000000+00:00 app[api]: Build succeeded 2019-09-10T22:25:38.839155+00:00 heroku[web.1]: Starting process with commandnpm start 2019-09-10T22:25:40.904305+00:00 app[web.1]: 2019-09-10T22:25:40.904322+00:00 app[web.1]: > Vidly_Node.js@1.0.0 start /app 2019-09-10T22:25:40.904324+00:00 app[web.1]: > node index.js 2019-09-10T22:25:40.904326+00:00 app[web.1]: 2019-09-10T22:25:41.618034+00:00 app[web.1]: WARNING: NODE_ENV value of 'production' did not match any deployment config file names. 2019-09-10T22:25:41.618562+00:00 app[web.1]: WARNING: See https://github.com/lorenwest/node-config/wiki/Strict-Mode 2019-09-10T22:25:41.841717+00:00 app[web.1]: (node:23) DeprecationWarning: current URL string parser is deprecated, and will be removed in a future version. To use the new parser, pass option { useNewUrlParser: true } to MongoClient.connect. 2019-09-10T22:25:41.844331+00:00 app[web.1]: {"message":"Listening on port 5000...","level":"info"} 2019-09-10T22:25:42.022695+00:00 app[web.1]: {"error":{"name":"MongoNetworkError","errorLabels":["TransientTransactionError"]},"level":"error","message":"uncaughtException: failed to connect to server [vidly-shard-00-01-9gnfk.mongodb.net:27017] on first connect [MongoNetworkError: connection 5 to vidly-shard-00-01-9gnfk.mongodb.net:27017 closed]\nMongoNetworkError: failed to connect to server [vidly-shard-00-01-9gnfk.mongodb.net:27017] on first connect [MongoNetworkError: connection 5 to vidly-shard-00-01-9gnfk.mongodb.net:27017 closed]\n at Pool.<anonymous> (/app/node_modules/mongodb-core/lib/topologies/server.js:431:11)\n at Pool.emit (events.js:198:13)\n at connect (/app/node_modules/mongodb-core/lib/connection/pool.js:557:14)\n at callback (/app/node_modules/mongodb-core/lib/connection/connect.js:109:5)\n at runCommand (/app/node_modules/mongodb-core/lib/connection/connect.js:129:7)\n at Connection.errorHandler (/app/node_modules/mongodb-core/lib/connection/connect.js:321:5)\n at Object.onceWrapper (events.js:286:20)\n at Connection.emit (events.js:198:13)\n at TLSSocket.<anonymous> (/app/node_modules/mongodb-core/lib/connection/connection.js:350:12)\n at Object.onceWrapper (events.js:286:20)\n at TLSSocket.emit (events.js:198:13)\n at _handle.close (net.js:606:12)\n at TCP.done (_tls_wrap.js:388:7)","stack":"MongoNetworkError: failed to connect to server [vidly-shard-00-01-9gnfk.mongodb.net:27017] on first connect [MongoNetworkError: connection 5 to vidly-shard-00-01-9gnfk.mongodb.net:27017 closed]\n at Pool.<anonymous> (/app/node_modules/mongodb-core/lib/topologies/server.js:431:11)\n at Pool.emit (events.js:198:13)\n at connect (/app/node_modules/mongodb-core/lib/connection/pool.js:557:14)\n at callback (/app/node_modules/mongodb-core/lib/connection/connect.js:109:5)\n at runCommand (/app/node_modules/mongodb-core/lib/connection/connect.js:129:7)\n at Connection.errorHandler (/app/node_modules/mongodb-core/lib/connection/connect.js:321:5)\n at Object.onceWrapper (events.js:286:20)\n at Connection.emit (events.js:198:13)\n at TLSSocket.<anonymous> (/app/node_modules/mongodb-core/lib/connection/connection.js:350:12)\n at Object.onceWrapper (events.js:286:20)\n at TLSSocket.emit (events.js:198:13)\n at _handle.close (net.js:606:12)\n at TCP.done (_tls_wrap.js:388:7)","exception":true,"date":"Tue Sep 10 2019 22:25:42 GMT+0000 (Coordinated Universal Time)","process":{"pid":23,"uid":22531,"gid":22531,"cwd":"/app","execPath":"/app/.heroku/node/bin/node","version":"v10.16.0","argv":["/app/.heroku/node/bin/node","/app/index.js"],"memoryUsage":{"rss":82886656,"heapTotal":62169088,"heapUsed":25412032,"external":18262612}},"os":{"loadavg":[3.90625,6.11376953125,8.89306640625],"uptime":892987},"trace":[{"column":11,"file":"/app/node_modules/mongodb-core/lib/topologies/server.js","function":null,"line":431,"method":null,"native":false},{"column":13,"file":"events.js","function":"Pool.emit","line":198,"method":"emit","native":false},{"column":14,"file":"/app/node_modules/mongodb-core/lib/connection/pool.js","function":"connect","line":557,"method":null,"native":false},{"column":5,"file":"/app/node_modules/mongodb-core/lib/connection/connect.js","function":"callback","line":109,"method":null,"native":false},{"column":7,"file":"/app/node_modules/mongodb-core/lib/connection/connect.js","function":"runCommand","line":129,"method":null,"native":false},{"column":5,"file":"/app/node_modules/mongodb-core/lib/connection/connect.js","function":"Connection.errorHandler","line":321,"method":"errorHandler","native":false},{"column":20,"file":"events.js","function":"Object.onceWrapper","line":286,"method":"onceWrapper","native":false},{"column":13,"file":"events.js","function":"Connection.emit","line":198,"method":"emit","native":false},{"column":12,"file":"/app/node_modules/mongodb-core/lib/connection/connection.js","function":null,"line":350,"method":null,"native":false},{"column":20,"file":"events.js","function":"Object.onceWrapper","line":286,"method":"onceWrapper","native":false},{"column":13,"file":"events.js","function":"TLSSocket.emit","line":198,"method":"emit","native":false},{"column":12,"file":"net.js","function":"_handle.close","line":606,"method":"close","native":false},{"column":7,"file":"_tls_wrap.js","function":"TCP.done","line":388,"method":"done","native":false}]} 2019-09-10T22:25:45.115380+00:00 heroku[web.1]: State changed from starting to crashed 2019-09-10T22:25:45.035380+00:00 app[web.1]: npm ERR! code ELIFECYCLE 2019-09-10T22:25:45.035882+00:00 app[web.1]: npm ERR! errno 1 2019-09-10T22:25:45.037140+00:00 app[web.1]: npm ERR! Vidly_Node.js@1.0.0 start:node index.js 2019-09-10T22:25:45.037317+00:00 app[web.1]: npm ERR! Exit status 1 2019-09-10T22:25:45.039203+00:00 app[web.1]: npm ERR! 2019-09-10T22:25:45.039592+00:00 app[web.1]: npm ERR! Failed at the Vidly_Node.js@1.0.0 start script. 2019-09-10T22:25:45.039950+00:00 app[web.1]: npm ERR! This is probably not a problem with npm. There is likely additional logging output above. 2019-09-10T22:25:45.048694+00:00 app[web.1]: 2019-09-10T22:25:45.048842+00:00 app[web.1]: npm ERR! A complete log of this run can be found in: 2019-09-10T22:25:45.048919+00:00 app[web.1]: npm ERR! /app/.npm/_logs/2019-09-10T22_25_45_042Z-debug.log 2019-09-10T22:25:45.099192+00:00 heroku[web.1]: Process exited with status 1

This is what I could make out to be the relevant portion of the uncaughtExceptions.log file: {"error":{"name":"MongoNetworkError","errorLabels":["TransientTransactionError"]},"level":"error","message":"uncaughtException: failed to connect to server [localhost:27017] on first connect [MongoNetworkError: connect ECONNREFUSED 127.0.0.1:27017]\nMongoNetworkError: failed to connect to server [localhost:27017] on first connect [MongoNetworkError: connect ECONNREFUSED 127.0.0.1:27017]\n at Pool.<anonymous>

MrPaz commented 4 years ago

It's actually easier to read the first log when it's not formatted as code:

heroku logs 2019-09-10T22:24:39.000000+00:00 app[api]: Build started by user randombsthrowaway@gmail.com 2019-09-10T22:25:36.350660+00:00 heroku[web.1]: State changed from crashed to starting 2019-09-10T22:25:35.910501+00:00 app[api]: Deploy 93a36670 by user randombsthrowaway@gmail.com 2019-09-10T22:25:35.910501+00:00 app[api]: Release v7 created by user randombsthrowaway@gmail.com 2019-09-10T22:25:36.000000+00:00 app[api]: Build succeeded 2019-09-10T22:25:38.839155+00:00 heroku[web.1]: Starting process with command npm start 2019-09-10T22:25:40.904305+00:00 app[web.1]: 2019-09-10T22:25:40.904322+00:00 app[web.1]: > Vidly_Node.js@1.0.0 start /app 2019-09-10T22:25:40.904324+00:00 app[web.1]: > node index.js 2019-09-10T22:25:40.904326+00:00 app[web.1]: 2019-09-10T22:25:41.618034+00:00 app[web.1]: WARNING: NODE_ENV value of 'production' did not match any deployment config file names. 2019-09-10T22:25:41.618562+00:00 app[web.1]: WARNING: See https://github.com/lorenwest/node-config/wiki/Strict-Mode 2019-09-10T22:25:41.841717+00:00 app[web.1]: (node:23) DeprecationWarning: current URL string parser is deprecated, and will be removed in a future version. To use the new parser, pass option { useNewUrlParser: true } to MongoClient.connect. 2019-09-10T22:25:41.844331+00:00 app[web.1]: {"message":"Listening on port 5000...","level":"info"} 2019-09-10T22:25:42.022695+00:00 app[web.1]: {"error":{"name":"MongoNetworkError","errorLabels":["TransientTransactionError"]},"level":"error","message":"uncaughtException: failed to connect to server [vidly-shard-00-01-9gnfk.mongodb.net:27017] on first connect [MongoNetworkError: connection 5 to vidly-shard-00-01-9gnfk.mongodb.net:27017 closed]\nMongoNetworkError: failed to connect to server [vidly-shard-00-01-9gnfk.mongodb.net:27017] on first connect [MongoNetworkError: connection 5 to vidly-shard-00-01-9gnfk.mongodb.net:27017 closed]\n at Pool. (/app/node_modules/mongodb-core/lib/topologies/server.js:431:11)\n at Pool.emit (events.js:198:13)\n at connect (/app/node_modules/mongodb-core/lib/connection/pool.js:557:14)\n at callback (/app/node_modules/mongodb-core/lib/connection/connect.js:109:5)\n at runCommand (/app/node_modules/mongodb-core/lib/connection/connect.js:129:7)\n at Connection.errorHandler (/app/node_modules/mongodb-core/lib/connection/connect.js:321:5)\n at Object.onceWrapper (events.js:286:20)\n at Connection.emit (events.js:198:13)\n at TLSSocket. (/app/node_modules/mongodb-core/lib/connection/connection.js:350:12)\n at Object.onceWrapper (events.js:286:20)\n at TLSSocket.emit (events.js:198:13)\n at _handle.close (net.js:606:12)\n at TCP.done (_tls_wrap.js:388:7)","stack":"MongoNetworkError: failed to connect to server [vidly-shard-00-01-9gnfk.mongodb.net:27017] on first connect [MongoNetworkError: connection 5 to vidly-shard-00-01-9gnfk.mongodb.net:27017 closed]\n at Pool. (/app/node_modules/mongodb-core/lib/topologies/server.js:431:11)\n at Pool.emit (events.js:198:13)\n at connect (/app/node_modules/mongodb-core/lib/connection/pool.js:557:14)\n at callback (/app/node_modules/mongodb-core/lib/connection/connect.js:109:5)\n at runCommand (/app/node_modules/mongodb-core/lib/connection/connect.js:129:7)\n at Connection.errorHandler (/app/node_modules/mongodb-core/lib/connection/connect.js:321:5)\n at Object.onceWrapper (events.js:286:20)\n at Connection.emit (events.js:198:13)\n at TLSSocket. (/app/node_modules/mongodb-core/lib/connection/connection.js:350:12)\n at Object.onceWrapper (events.js:286:20)\n at TLSSocket.emit (events.js:198:13)\n at _handle.close (net.js:606:12)\n at TCP.done (_tls_wrap.js:388:7)","exception":true,"date":"Tue Sep 10 2019 22:25:42 GMT+0000 (Coordinated Universal Time)","process":{"pid":23,"uid":22531,"gid":22531,"cwd":"/app","execPath":"/app/.heroku/node/bin/node","version":"v10.16.0","argv":["/app/.heroku/node/bin/node","/app/index.js"],"memoryUsage":{"rss":82886656,"heapTotal":62169088,"heapUsed":25412032,"external":18262612}},"os":{"loadavg":[3.90625,6.11376953125,8.89306640625],"uptime":892987},"trace":[{"column":11,"file":"/app/node_modules/mongodb-core/lib/topologies/server.js","function":null,"line":431,"method":null,"native":false},{"column":13,"file":"events.js","function":"Pool.emit","line":198,"method":"emit","native":false},{"column":14,"file":"/app/node_modules/mongodb-core/lib/connection/pool.js","function":"connect","line":557,"method":null,"native":false},{"column":5,"file":"/app/node_modules/mongodb-core/lib/connection/connect.js","function":"callback","line":109,"method":null,"native":false},{"column":7,"file":"/app/node_modules/mongodb-core/lib/connection/connect.js","function":"runCommand","line":129,"method":null,"native":false},{"column":5,"file":"/app/node_modules/mongodb-core/lib/connection/connect.js","function":"Connection.errorHandler","line":321,"method":"errorHandler","native":false},{"column":20,"file":"events.js","function":"Object.onceWrapper","line":286,"method":"onceWrapper","native":false},{"column":13,"file":"events.js","function":"Connection.emit","line":198,"method":"emit","native":false},{"column":12,"file":"/app/node_modules/mongodb-core/lib/connection/connection.js","function":null,"line":350,"method":null,"native":false},{"column":20,"file":"events.js","function":"Object.onceWrapper","line":286,"method":"onceWrapper","native":false},{"column":13,"file":"events.js","function":"TLSSocket.emit","line":198,"method":"emit","native":false},{"column":12,"file":"net.js","function":"_handle.close","line":606,"method":"close","native":false},{"column":7,"file":"_tls_wrap.js","function":"TCP.done","line":388,"method":"done","native":false}]} 2019-09-10T22:25:45.115380+00:00 heroku[web.1]: State changed from starting to crashed 2019-09-10T22:25:45.035380+00:00 app[web.1]: npm ERR! code ELIFECYCLE 2019-09-10T22:25:45.035882+00:00 app[web.1]: npm ERR! errno 1 2019-09-10T22:25:45.037140+00:00 app[web.1]: npm ERR! Vidly_Node.js@1.0.0 start: node index.js 2019-09-10T22:25:45.037317+00:00 app[web.1]: npm ERR! Exit status 1 2019-09-10T22:25:45.039203+00:00 app[web.1]: npm ERR! 2019-09-10T22:25:45.039592+00:00 app[web.1]: npm ERR! Failed at the Vidly_Node.js@1.0.0 start script. 2019-09-10T22:25:45.039950+00:00 app[web.1]: npm ERR! This is probably not a problem with npm. There is likely additional logging output above. 2019-09-10T22:25:45.048694+00:00 app[web.1]: 2019-09-10T22:25:45.048842+00:00 app[web.1]: npm ERR! A complete log of this run can be found in: 2019-09-10T22:25:45.048919+00:00 app[web.1]: npm ERR! /app/.npm/_logs/2019-09-10T22_25_45_042Z-debug.log 2019-09-10T22:25:45.099192+00:00 heroku[web.1]: Process exited with status 1

AgusDG commented 4 years ago

Hey @MrPaz, Im facing the same problem than you:

"uncaughtException: failed to connect to server [vidly-shard-00-01-9gnfk.mongodb.net:27017] on first connect [MongoNetworkError: connection 5 to vidly-shard-00-01-9gnfk.mongodb.net:27017 closed]"

I can perfectly connect to my db on Compass, but Im getting the same error. Did you solve it?

AgusDG commented 4 years ago

Solved. When you receive an error like "MongoError: connection 4 to vidly-shard-00-01-dosly.mongodb.net:27017 closed" you have to whitelist all IP addresses in MongoDB security options.

Step #2: In MongoDB Atlas, WHITELIST ALL IP ADDRESSES. As of May 2019, you can do this by going to Security (left panel) => Network Access => Actions (center-right) => EDIT => Whitelist Entry: => 0.0.0.0/0.

I followed the steps in this post in the forum.

https://forum.codewithmosh.com/d/694-may-2019-summary-of-react-tutorial-vidly-node-deployment-fixes

udayaugustin commented 3 years ago

Please check the connection string after whitelisting the API.

The connection string will look like below for node 3.6 or later. sample connection string : <vairablename>=mongodb+srv://<user>:<password>@vidly.wrejo.mongodb.net/<dbname>?retryWrites=true&w=majority sample environment variable : heroku config:set<vairablename>=mongodb+srv://<user>:<password>@vidly.wrejo.mongodb.net/<dbname>?retryWrites=true&w=majority

For an earlier version, you need to get the appropriate string from the MongoDB Atlas. In dashboard Click Connect-> Connect your application -> Choose the version. You can see the connection string specific to that version.

Screenshot 2021-04-07 at 3 23 35 PM
alisadeghi98 commented 1 year ago

any update ?