Internal Server Error

[yuri-karadzhov]

Sometimes I get 'Internal Server Error' when I try to log in with LinkedIn. Other strategies works well and I have no errors in the log.

The route is http://skwibl.com/auth/linkedin/callback?oauth_token=some-long-token&oauth_verifier=someverifier.

The problem is it works sometimes and sometimes don't. If I log in with google then log out then log in back with linkedin (have the same email) it works. But if I log out then leave the page, enter the page and try to connect with linkedin - it doesn't work. There are no errors in the log and the only thing I got is 'Internal Server Error' message in the browser.

I tried node 0.8 and 0.10.

[yuri-karadzhov]

I found an error. It was ignored by the logger for some reasons

Error: failed to find request token in session
    at Strategy.OAuthStrategy.authenticate (/var/www/skwibl/node_modules/passport-linkedin/node_modules/passport-oauth/lib/passport-oauth/strategies/oauth.js:123:54)
    at Strategy.authenticate (/var/www/skwibl/node_modules/passport-linkedin/lib/passport-linkedin/strategy.js:118:40)
    at attempt (/var/www/skwibl/node_modules/passport/lib/passport/middleware/authenticate.js:243:16)
    at Passport.authenticate (/var/www/skwibl/node_modules/passport/lib/passport/middleware/authenticate.js:244:7)
    at callbacks (/var/www/skwibl/node_modules/express/lib/router/index.js:161:37)
    at param (/var/www/skwibl/node_modules/express/lib/router/index.js:135:11)
    at pass (/var/www/skwibl/node_modules/express/lib/router/index.js:142:5)
    at Router._dispatch (/var/www/skwibl/node_modules/express/lib/router/index.js:170:5)
    at Object.router (/var/www/skwibl/node_modules/express/lib/router/index.js:33:10)
    at next (/var/www/skwibl/node_modules/express/node_modules/connect/lib/proto.js:199:15)

[jaredhanson]

This is similar to passport-twitter #12.

What are you using for session storage and are you running a cluster? This seems to be a sporadic error, and I'm curious if it is caused by using an eventually-consistent session store. For example, if you have a distributed MongoDB setup and a session restore query would hit a slave which may not yet have the session data.

Any insights you could give into this are helpful, as no root cause has been found for this issue.

[yuri-karadzhov]

We use redis as session storage and we use cluster (but now we run the server on single core). Strange thing is that it works fine with other strategies and we didn't have any problems with passport-linkedin before (and it works localy right now, but not on the production).

[vladberteanu]

We are not using cluster, mongoDB is not distributed and still see the error from time to time. Maybe connect-mongo for sessions might have a bug.

[vladberteanu]

On another server I'm running the same setup but I use facebook strategy, and from time to time I see:

127.0.0.1 - - [Sat, 02 Mar 2013 02:26:19 GMT] "GET /app/auth/facebook HTTP/1.1" 302 478 "http://practice.talentbuddy.co/?utm_source=facebook&utm_medium=cpc&utm_content=asia1-students&utm_campaign=fitness" "Mozilla/5.0 (Windows NT 6.1; WOW64) AppleWebKit/537.22 (KHTML, like Gecko) Chrome/25.0.1364.97 Safari/537.22" failed to obtain access token (status: 400 data: {"error":{"message":"Invalid verification code format.","type":"OAuthException","code":100}}) at /home/ubuntu/talentbuddy/web/node_modules/passport-facebook/node_modules/passport-oauth/lib/passport-oauth/strategies/oauth2.js:125:38

The domain used to make the request to facebook and the domain in the facebook callback always match.

[yuri-karadzhov]

I add console.log(req.session) in stratage.js file on line 106 (passport-linkedin/lib/passport-linkedin/strategy.js) and I get output two times per login:

{ cookie: 
   { path: '/',
     _expires: null,
     originalMaxAge: null,
     httpOnly: true },
  passport: {},
  'oauth:linkedin': 
   { oauth_token: 'some-long-token',
     oauth_token_secret: 'some-token-secret' } }

the first one is good cause it has oauth:linkedin key

{ cookie: 
   { path: '/',
     _expires: null,
     originalMaxAge: null,
     httpOnly: true },
  passport: {},
  flash: {} }

and now it disappears =(

The question is why do we have two calls to strategy.authenticate(req, opts) and why req.session is changed?

UPD: In case when auth succed - we also have two calls but in inverse order.

[yuri-karadzhov]

Get it! We call authenticate twice, first - when we try to login, second, when we obtain callback. So it appears, that the problem is - sometimes callback is parsed before the login attempt is processed.

Update: It is not true. It is problem with sessions.

[yuri-karadzhov]

Ok. I dig into the problem and it seems it is problem with firefox and session. In some unknown reason firefox create new session after i left the page and then enter it again. However this problem do not affect facebook and google authorization, the session still do not work properly, but it is possible to login with these strategies.

[yuri-karadzhov]

Firefox (Linux and Windows, MacOs works fine) create different session cookies for service.com and www.service.com - that cause the problem with sessions. Are there any ideas how to fix it?

[yuri-karadzhov]

I found a solution here http://stackoverflow.com/questions/7074509/how-do-i-make-my-sessions-last-cross-subdomain-in-node-js-express It is not a problem with passport-linkedin, however it can be more robust like fb and g+ and do not cause errors.