Attempting to implement authentication using node, passport and mysql, running on heroku, starting from this code, which uses MongoDB:
http://scotch.io/tutorials/javascript/easy-node-authentication-setup-and-local
The code at the URL above has been migrated from MongoDB to MySQL. The result is at the github project below. But that project only has local login. Social authentication (Facebook, Twitter, Google+) was not included.
https://github.com/manjeshpv/node-express-passport-mysql
I'm currently working on integrating Facebook authentication.
My Facebook strategy (in passport.js) currently looks like this:
passport.use(new FacebookStrategy({
clientID : configAuth.facebookAuth.clientID,
clientSecret : configAuth.facebookAuth.clientSecret,
callbackURL : configAuth.facebookAuth.callbackURL,
passReqToCallback : true // allows us to pass in the req from our route (lets us check if a user is logged in or not)
},
function(req, token, refreshToken, profile, done) {
// asynchronous
process.nextTick(function() {
// check if the user is already logged in
if (!req.user) {
console.log ("mylog: user is not logged in");
connection.query("select * from users where facebook_id = '" + profile.id + "'",function(err, rows){
console.log ("mylog: select from users where facebook_id = "+profile.id);
if (err) {
console.log ("mylog: err in connection.query");
return done(err);
}
if (!rows.length) {
console.log ("mylog: no rows with facebook_id = "+profile.id);
return done(null, false, req.flash('loginMessage', 'No user found.')); // req.flash to set flashdata using connect-flash
}
}
);
} else {
console.log ("mylog: user already exists and is logged in; link accounts");
// user already exists and is logged in, we have to link accounts
}
});
}));
The Heroku log shows that the program flow is getting to the "no rows with facebook_id" point and attempting to do a Facebook authorization, but the Facebook screen asking for the user's permission never comes up. Instead, it just stays on the home page with the login buttons (which looks similar to this: http://node-authentication.azurewebsites.net/). The URL does change in that /#= gets added on to the end of it. In addition, the flash message 'No user found.' never appears.
Below are the final lines of the log. (Deleted items are indicated by [deleted] )
2014-09-03T02:20:39.167496+00:00 app[web.1]: GET / 304 22ms
2014-09-03T02:20:43.170128+00:00 heroku[router]: at=info method=GET path="/auth/facebook" host=scotch-mysql2.herokuapp.com request_id=fd22f72d-bc9e-489b-a874-8c10995693a8 fwd="207.118.16.184" dyno=web.1 connect=1ms service=14ms status=302 bytes=735
2014-09-03T02:20:43.168932+00:00 app[web.1]: GET /auth/facebook 302 9ms - 434b
2014-09-03T02:20:43.937938+00:00 heroku[router]: at=info method=GET path="/auth/facebook/callback?code=[deleted]" host=scotch-mysql2.herokuapp.com request_id=e42c84bf-371f-4432-a1d9-3e0b65dd235c fwd="207.118.16.184" dyno=web.1 connect=2ms service=486ms status=302 bytes=1073
2014-09-03T02:20:43.926654+00:00 app[web.1]: mylog: user is not logged in
2014-09-03T02:20:44.107277+00:00 app[web.1]: GET / 304 7ms
2014-09-03T02:20:43.934743+00:00 app[web.1]: GET /auth/facebook/callback?code=[deleted] 302 482ms - 58b
2014-09-03T02:20:43.932928+00:00 app[web.1]: mylog: no rows with facebook_id = [deleted]
2014-09-03T02:20:43.932899+00:00 app[web.1]: mylog: select from users where facebook_id = [deleted]
2014-09-03T02:20:44.108391+00:00 heroku[router]: at=info method=GET path="/" host=scotch-mysql2.herokuapp.com request_id=9f72f73f-4244-40f2-9600-5622512dd5ff fwd="207.118.16.184" dyno=web.1 connect=1ms service=8ms status=304 bytes=751
Any suggestions on how I might proceed will be greatly appreciated.
=======================================================================
Hmmmm. Just tried this again and got a different result.
When I clicked the "Facebook" button, it went to http://example.com/auth/facebook where I got the standard Heroku "Application Error" screen. The Heroku log doesn't show any of my console.log messages:
2014-09-03T18:10:29.919910+00:00 app[web.1]: npm ERR! npm owner ls node-authentication
2014-09-03T18:10:29.920006+00:00 app[web.1]: npm ERR! There is likely additional logging output above.
2014-09-03T18:10:29.920245+00:00 app[web.1]: npm ERR! System Linux 3.8.11-ec2
2014-09-03T18:10:29.920369+00:00 app[web.1]: npm ERR! command "/app/vendor/node/bin/node" "/app/vendor/node/bin/npm" "start"
2014-09-03T18:10:29.920489+00:00 app[web.1]: npm ERR! cwd /app
2014-09-03T18:10:29.920596+00:00 app[web.1]: npm ERR! node -v v0.10.31
2014-09-03T18:10:29.920712+00:00 app[web.1]: npm ERR! npm -v 1.4.23
2014-09-03T18:10:29.920823+00:00 app[web.1]: npm ERR! code ELIFECYCLE
2014-09-03T18:10:29.922395+00:00 app[web.1]: npm ERR!
2014-09-03T18:10:29.922536+00:00 app[web.1]: npm ERR! Additional logging details can be found in:
2014-09-03T18:10:29.922686+00:00 app[web.1]: npm ERR! /app/npm-debug.log
2014-09-03T18:10:29.922938+00:00 app[web.1]: npm ERR! not ok code 0
2014-09-03T18:10:30.527070+00:00 heroku[web.1]: State changed from up to crashed
2014-09-03T18:08:59.317562+00:00 app[web.1]:
2014-09-03T18:08:59.317593+00:00 app[web.1]: > node-authentication@ start /app
2014-09-03T18:08:59.317595+00:00 app[web.1]: > node ./server
2014-09-03T18:08:59.317596+00:00 app[web.1]:
2014-09-03T18:17:31.869962+00:00 app[web.1]: GET / 304 6ms
2014-09-03T18:16:54.581743+00:00 heroku[router]: at=error code=H10 desc="App crashed" method=GET path="/" host=scotch-mysql2.herokuapp.com request_id=36336861-fd61-4f65-93f5-e712a4ed60fb fwd="207.118.16.184" dyno= connect= service= status=503 bytes=
2014-09-03T18:17:21.242518+00:00 app[web.1]: visit https://github.com/senchalabs/connect/wiki/Connect-3.0 for alternatives
2014-09-03T18:17:21.263373+00:00 app[web.1]: The magic happens on port 27334
2014-09-03T18:18:51.327700+00:00 app[web.1]: at _stream_readable.js:943:16
2014-09-03T18:18:51.327698+00:00 app[web.1]: at Socket.<anonymous> (/app/node_modules/mysql/lib/Connection.js:88:28)
2014-09-03T18:18:51.327702+00:00 app[web.1]: at process._tickCallback (node.js:419:13)
2014-09-03T18:18:51.327690+00:00 app[web.1]: Error: Connection lost: The server closed the connection.
2014-09-03T18:18:51.327699+00:00 app[web.1]: at Socket.emit (events.js:117:20)
2014-09-03T18:18:51.327696+00:00 app[web.1]: at Protocol.end (/app/node_modules/mysql/lib/protocol/Protocol.js:103:13)
2014-09-03T18:18:51.354275+00:00 app[web.1]:
2014-09-03T18:18:52.247941+00:00 heroku[web.1]: Process exited with status 1
2014-09-03T18:17:21.476712+00:00 heroku[web.1]: State changed from starting to up
2014-09-03T18:17:22.256702+00:00 app[web.1]: GET / 200 47ms - 1.39kb
2014-09-03T18:17:31.869740+00:00 heroku[router]: at=info method=GET path="/" host=scotch-mysql2.herokuapp.com request_id=f0ae72e9-e6e4-4f25-847e-696f436bd8e2 fwd="207.118.16.184" dyno=web.1 connect=1ms service=8ms status=304 bytes=701
2014-09-03T18:18:51.367328+00:00 app[web.1]: npm ERR! Exit status 8
2014-09-03T18:18:51.368424+00:00 app[web.1]: npm ERR! node ./server
2014-09-03T18:18:51.373067+00:00 app[web.1]: npm ERR! code ELIFECYCLE
2014-09-03T18:18:51.372843+00:00 app[web.1]: npm ERR! npm -v 1.4.23
2014-09-03T18:18:51.379552+00:00 app[web.1]: npm ERR! not ok code 0
2014-09-03T18:18:51.367103+00:00 app[web.1]: npm ERR! node-authentication@ start: `node ./server`
2014-09-03T18:18:51.368520+00:00 app[web.1]: npm ERR! You can get their info via:
2014-09-03T18:18:51.379104+00:00 app[web.1]: npm ERR! /app/npm-debug.log
2014-09-03T18:18:51.368703+00:00 app[web.1]: npm ERR! There is likely additional logging output above.
2014-09-03T18:18:51.368225+00:00 app[web.1]: npm ERR! not with npm itself.
2014-09-03T18:18:51.378943+00:00 app[web.1]: npm ERR! Additional logging details can be found in:
2014-09-03T18:18:51.368137+00:00 app[web.1]: npm ERR! This is most likely a problem with the node-authentication package,
2014-09-03T18:18:51.367487+00:00 app[web.1]: npm ERR!
2014-09-03T18:18:51.368327+00:00 app[web.1]: npm ERR! Tell the author that this fails on your system:
2014-09-03T18:18:51.368982+00:00 app[web.1]: npm ERR! System Linux 3.8.11-ec2
2014-09-03T18:18:51.378766+00:00 app[web.1]: npm ERR!
2014-09-03T18:18:51.319785+00:00 app[web.1]:
2014-09-03T18:18:51.372189+00:00 app[web.1]: npm ERR! command "/app/vendor/node/bin/node" "/app/vendor/node/bin/npm" "start"
2014-09-03T18:18:51.367584+00:00 app[web.1]: npm ERR! Failed at the node-authentication@ start script.
2014-09-03T18:18:51.368606+00:00 app[web.1]: npm ERR! npm owner ls node-authentication
2014-09-03T18:18:51.372425+00:00 app[web.1]: npm ERR! cwd /app
2014-09-03T18:18:51.372628+00:00 app[web.1]: npm ERR! node -v v0.10.31
2014-09-03T18:18:55.524834+00:00 heroku[web.1]: State changed from starting to up
2014-09-03T18:17:22.251709+00:00 heroku[router]: at=info method=GET path="/" host=scotch-mysql2.herokuapp.com request_id=dab05119-ec75-41b5-8b42-c334c62db172 fwd="207.118.16.184" dyno=web.1 connect=1ms service=48ms status=200 bytes=698
2014-09-03T18:17:11.291654+00:00 heroku[api]: Scale to web=0 by mhurwicz@gmail.com
2014-09-03T18:17:19.056512+00:00 heroku[web.1]: Starting process with command `npm start`
2014-09-03T18:17:21.242030+00:00 app[web.1]: connect.multipart() will be removed in connect 3.0
2014-09-03T18:17:21.242845+00:00 app[web.1]: connect.limit() will be removed in connect 3.0
2014-09-03T18:20:25.790757+00:00 app[web.1]: at Socket.emit (events.js:117:20)
2014-09-03T18:20:25.790751+00:00 app[web.1]: Error: Connection lost: The server closed the connection.
2014-09-03T18:20:25.790754+00:00 app[web.1]: at Protocol.end (/app/node_modules/mysql/lib/protocol/Protocol.js:103:13)
2014-09-03T18:20:25.797006+00:00 app[web.1]:
2014-09-03T18:18:54.971529+00:00 app[web.1]: connect.multipart() will be removed in connect 3.0
2014-09-03T18:18:54.972286+00:00 app[web.1]: connect.limit() will be removed in connect 3.0
2014-09-03T18:20:25.790759+00:00 app[web.1]: at _stream_readable.js:943:16
2014-09-03T18:18:53.748192+00:00 heroku[web.1]: Starting process with command `npm start`
2014-09-03T18:20:25.790760+00:00 app[web.1]: at process._tickCallback (node.js:419:13)
2014-09-03T18:20:25.790756+00:00 app[web.1]: at Socket.<anonymous> (/app/node_modules/mysql/lib/Connection.js:88:28)
2014-09-03T18:18:54.602435+00:00 app[web.1]:
2014-09-03T18:18:54.602455+00:00 app[web.1]: > node-authentication@ start /app
2014-09-03T18:18:54.602457+00:00 app[web.1]: > node ./server
2014-09-03T18:18:54.602458+00:00 app[web.1]:
2014-09-03T18:20:25.788289+00:00 app[web.1]:
2014-09-03T18:20:25.802116+00:00 app[web.1]: npm ERR! node-authentication@ start: `node ./server`
2014-09-03T18:20:25.802306+00:00 app[web.1]: npm ERR! Exit status 8
2014-09-03T18:20:25.802442+00:00 app[web.1]: npm ERR!
2014-09-03T18:20:25.802568+00:00 app[web.1]: npm ERR! Failed at the node-authentication@ start script.
2014-09-03T18:20:25.803061+00:00 app[web.1]: npm ERR! This is most likely a problem with the node-authentication package,
2014-09-03T18:20:25.803162+00:00 app[web.1]: npm ERR! not with npm itself.
2014-09-03T18:20:25.803255+00:00 app[web.1]: npm ERR! Tell the author that this fails on your system:
2014-09-03T18:20:25.803357+00:00 app[web.1]: npm ERR! node ./server
2014-09-03T18:20:25.803462+00:00 app[web.1]: npm ERR! You can get their info via:
2014-09-03T18:20:25.803552+00:00 app[web.1]: npm ERR! npm owner ls node-authentication
2014-09-03T18:20:25.803650+00:00 app[web.1]: npm ERR! There is likely additional logging output above.
2014-09-03T18:20:25.803925+00:00 app[web.1]: npm ERR! System Linux 3.8.11-ec2
2014-09-03T18:20:25.804103+00:00 app[web.1]: npm ERR! command "/app/vendor/node/bin/node" "/app/vendor/node/bin/npm" "start"
2014-09-03T18:20:25.804254+00:00 app[web.1]: npm ERR! cwd /app
2014-09-03T18:20:25.804402+00:00 app[web.1]: npm ERR! node -v v0.10.31
2014-09-03T18:20:25.804539+00:00 app[web.1]: npm ERR! npm -v 1.4.23
2014-09-03T18:20:25.804697+00:00 app[web.1]: npm ERR! code ELIFECYCLE
2014-09-03T18:20:25.806170+00:00 app[web.1]: npm ERR!
2014-09-03T18:20:25.806324+00:00 app[web.1]: npm ERR! Additional logging details can be found in:
2014-09-03T18:20:25.806411+00:00 app[web.1]: npm ERR! /app/npm-debug.log
2014-09-03T18:20:25.806637+00:00 app[web.1]: npm ERR! not ok code 0
2014-09-03T18:20:18.532229+00:00 heroku[router]: at=info method=GET path="/" host=scotch-mysql2.herokuapp.com request_id=cab02f02-ca04-4003-97b3-e51ac53500a5 fwd="207.118.16.184" dyno=web.1 connect=9ms service=24ms status=304 bytes=727
2014-09-03T18:20:26.444391+00:00 heroku[web.1]: State changed from up to crashed
2014-09-03T18:20:18.539052+00:00 app[web.1]: GET / 304 17ms
2014-09-03T18:20:26.444418+00:00 heroku[web.1]: Process exited with status 1
2014-09-03T18:25:07.128654+00:00 heroku[router]: at=error code=H10 desc="App crashed" method=GET path="/auth/facebook" host=scotch-mysql2.herokuapp.com request_id=b028c414-159d-40ed-b8fc-99f71c892e29 fwd="207.118.16.184" dyno= connect= service= status=503 bytes=
==================================================================
Tried it again. This time is went to http://example.com/#= (like the first time) -- with the display still not changing, just showing the five buttons -- but this time none of my console.log messages appear in the logs. The final lines of the log are:
2014-09-03T18:48:56.623547+00:00 app[web.1]: GET /auth/facebook 302 8ms - 434b
2014-09-03T18:48:57.419398+00:00 heroku[router]: at=info method=GET path="/auth/facebook/callback?code=[deleted]" host=scotch-mysql2.herokuapp.com request_id=23be5f00-21b5-43a9-801e-13d40c534e18 fwd="207.118.16.184" dyno=web.1 connect=1ms service=439ms status=302 bytes=1067
2014-09-03T18:48:56.624353+00:00 heroku[router]: at=info method=GET path="/auth/facebook" host=scotch-mysql2.herokuapp.com request_id=a97b0683-bcca-476a-87ce-f798208116e7 fwd="207.118.16.184" dyno=web.1 connect=0ms service=10ms status=302 bytes=729
Also, sometimes if I try to refresh the home page after clicking the Facebook button, I get the Heroku "Application Error". Scaling to web=0 and then back to web=1 on the Heroku dashboard gets the home page displaying again.