vidly-api-node
vidly-api-node copied to clipboard
Node.js course - Error connecting to MongoDB in Heroku deploy
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 [email protected] 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 [email protected] 2019-09-10T22:25:35.910501+00:00 app[api]: Release v7 created by user [email protected] 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 start2019-09-10T22:25:40.904305+00:00 app[web.1]: 2019-09-10T22:25:40.904322+00:00 app[web.1]: > [email protected] 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! [email protected] 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 [email protected] 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>
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 [email protected] 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 [email protected] 2019-09-10T22:25:35.910501+00:00 app[api]: Release v7 created by user [email protected] 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]: > [email protected] 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! [email protected] 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 [email protected] 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
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?
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
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.

any update ?