Invalid invitation token until third view of invitation link

[bbrstw]

I have a rails 4 multitenant application using apartment, devise, devise_invitable, and postgres schemas. Versions are as follows...

Rails 4.1.5 devise 3.3.0
devise_invitable 1.3.6 Postgresql 9.3.5

I also have a publicly viewable git repo here: https://github.com/bbrstw/warehouse

I am able to create an invitation. Upon opening the invitation URL, the user is redirected to the sign in page with the flash error: The invitation token provided is not valid!

However, if I follow the link three times (i.e. follow the link once, paste the url into the browser and press enter to follow it again, and then repeat once more), on the third time I am directed to the complete signup page (devise/invitations/edit.html.erb), and I am able to accept the invitation and register. This happens every time, exactly on the third time each time. If I wait for a short while then follow the link again, I will again need to follow the link three times before finally being directed to the complete sign up page, as if a session times out and the click count resets or something.

I have tested this in Chrome, Firefox, Safari and Internet Explorer 10 all to the same effect. I have reproduced this on Mac OSX 10.9 and Windows 7 with the rails project at the git repo provided.

Here are some of the rails dev log read outs...

This block will appear twice with the first two times I follow the link (http://myaccount.lvh.me:3000/users/invitation/accept?invitation_token=sJ5d-ECNLqp38mi_sTmJ):

Started GET "/users/invitation/accept?invitation_token=sJ5d-ECNLqp38mi_sTmJ" for 127.0.0.1 at     2014-09-07 12:23:16 +0800
  ActiveRecord::SchemaMigration Load (2.2ms)  SELECT "schema_migrations".* FROM "schema_migrations"
Processing by InvitationsController#edit as HTML
  Parameters: {"invitation_token"=>"sJ5d-ECNLqp38mi_sTmJ"}
  User Load (4.4ms)  SELECT  "users".* FROM "users"  WHERE "users"."invitation_token" =  'b58b6e22ea9f3fe3d0b608fcb9910ee34b64dc3a809a13fe18d4d399631d7daf'  ORDER BY "users"."id"   ASC LIMIT 1
Redirected to http://myaccount.lvh.me:3000/users/sign_in
Filter chain halted as :resource_from_invitation_token rendered or redirected
Completed 302 Found in 837ms (ActiveRecord: 7.1ms)

Started GET "/users/sign_in" for 127.0.0.1 at 2014-09-07 12:23:17 +0800
Processing by Devise::SessionsController#new as HTML
  Account Load (1.4ms)  SELECT  "public"."accounts".* FROM "public"."accounts"  WHERE "public"."accounts"."subdomain" = 'myaccount' LIMIT 1
  Rendered devise/shared/_links.erb (1.7ms)
  Rendered devise/sessions/new.html.erb within layouts/application (54.6ms)
Completed 200 OK in 232ms (Views: 204.8ms | ActiveRecord: 4.9ms)

And then finally this block is logged upon successfully accepting token and serving the complete registration page...

Started GET "/users/invitation/accept?invitation_token=sJ5d-ECNLqp38mi_sTmJ" for 127.0.0.1 at 2014-09-07 12:23:26 +0800
Processing by InvitationsController#edit as HTML
  Parameters: {"invitation_token"=>"sJ5d-ECNLqp38mi_sTmJ"}
  User Load (755.8ms)  SELECT  "users".* FROM "users"  WHERE "users"."invitation_token" = 'b58b6e22ea9f3fe3d0b608fcb9910ee34b64dc3a809a13fe18d4d399631d7daf'  ORDER BY "users"."id" ASC LIMIT 1
  Account Load (0.3ms)  SELECT  "public"."accounts".* FROM "public"."accounts"  WHERE "public"."accounts"."subdomain" = 'myaccount' LIMIT 1
  Rendered devise/invitations/edit.html.erb within layouts/application (4.8ms)
Completed 200 OK in 784ms (Views: 23.0ms | ActiveRecord: 756.9ms)

Any ideas as to whether or not this is devise_invitable issue?

[scambra]

Can you check query on db when link fails and redirects to /users/sign_in?

[bbrstw]

Logged all queries in postgres to logfile as below....

/********************** First Request *************************/

LOG:  statement: SELECT 1
LOG:  statement: SET search_path TO "public"
LOG:  execute <unnamed>: SELECT  "users".* FROM "users"  WHERE "users"."invitation_token" =    '5211ae1ceaf7b50a467f3c11d318d2bc5df4ca5b30955b32069e2f936f6d8ee6'  ORDER BY "users"."id"     ASC LIMIT 1
LOG:  statement: SELECT 1
LOG:  execute <unnamed>:             SELECT COUNT(*)
            FROM pg_namespace
            WHERE nspname = 'public'

LOG:  statement: SET search_path TO "public"
LOG:  execute <unnamed>: SELECT  "public"."accounts".* FROM "public"."accounts"  WHERE    "public"."accounts"."subdomain" = 'testingtestingonetwo' LIMIT 1
LOG:  execute <unnamed>:             SELECT COUNT(*)
            FROM pg_namespace
            WHERE nspname = 'testingtestingonetwo'

LOG:  statement: SET search_path TO "testingtestingonetwo"
LOG:  statement: SELECT 1
LOG:  statement: SELECT 1
LOG:  statement: SET search_path TO "public"
LOG:  statement: SELECT 1
LOG:  statement: SET search_path TO "public"
LOG:  statement: SELECT 1
LOG:  statement: SET search_path TO "public"
LOG:  statement: SELECT 1
LOG:  statement: SET search_path TO "public"  
LOG:  statement: SELECT 1
LOG:  statement: SET search_path TO "public"
LOG:  statement: SELECT 1
LOG:  statement: SELECT 1
LOG:  statement: SELECT 1
LOG:  statement: SELECT 1
LOG:  statement: SELECT 1
LOG:  statement: SELECT 1
LOG:  statement: SELECT 1
LOG:  statement: SELECT 1
LOG:  statement: SELECT 1
LOG:  statement: SELECT 1
LOG:  statement: SELECT 1
LOG:  statement: SELECT 1
LOG:  statement: SELECT 1
LOG:  statement: SELECT 1

/*************************** Second Request ***************************/

LOG:  statement: SELECT 1
LOG:  execute <unnamed>: SELECT  "users".* FROM "users"  WHERE "users"."invitation_token" = '5211ae1ceaf7b50a467f3c11d318d2bc5df4ca5b30955b32069e2f936f6d8ee6'  ORDER BY "users"."id" ASC LIMIT 1
LOG:  statement: SELECT 1
LOG:  execute <unnamed>:             SELECT COUNT(*)
                FROM pg_namespace
                WHERE nspname = 'public'

LOG:  statement: SET search_path TO "public"
LOG:  execute <unnamed>: SELECT  "public"."accounts".* FROM "public"."accounts"  WHERE "public"."accounts"."subdomain" = 'testingtestingonetwo' LIMIT 1
LOG:  execute <unnamed>:             SELECT COUNT(*)
                FROM pg_namespace
                WHERE nspname = 'testingtestingonetwo'

LOG:  statement: SET search_path TO "testingtestingonetwo"

/*************************** Third (Successful) Request ******************/

LOG:  statement: SELECT 1
LOG:  execute <unnamed>: SELECT  "users".* FROM "users"  WHERE "users"."invitation_token" = '5211ae1ceaf7b50a467f3c11d318d2bc5df4ca5b30955b32069e2f936f6d8ee6'  ORDER BY "users"."id" ASC LIMIT 1
LOG:  execute <unnamed>:             SELECT COUNT(*)
                FROM pg_namespace
                WHERE nspname = 'public'

LOG:  statement: SET search_path TO "public"
LOG:  execute <unnamed>: SELECT  "public"."accounts".* FROM "public"."accounts"  WHERE "public"."accounts"."subdomain" = 'testingtestingonetwo' LIMIT 1
LOG:  execute <unnamed>:             SELECT COUNT(*)
                FROM pg_namespace
                WHERE nspname = 'testingtestingonetwo'

LOG:  statement: SET search_path TO "testingtestingonetwo"
LOG:  statement: SELECT 1
LOG:  statement: SELECT 1

The token being queried for matches what is in the database on users table for this particular user invitation. Still, find_by_invitation_token returns nil almost every time, which I'm checking via an inspect printed to log after the function is called in my invitations controller method resource_from_invitation_token.

[scambra]

When first request fails, if you go to postgres db, can you find the user there, with that token? Is it querying right db?

[L33tH4x0r]

Hey! Running into the same issue. We have a multi tenant application and some of our users are unable to set their passwords when they follow the links from the email we send them.

We are running: Ruby: 2.3.4 Rails: 5.0.4 Apartment: 1.2.0 Devise: 4.3.0 Devise Invitable: 1.7.2

We have our server running on Heroku and use Postgres as our database.

[rks92]

@scambra Facing the exact same issue as @L33tH4x0r . Any luck in resolving this?

[scambra]

I think only multi tenant apps have this issue. If anyone can reproduce with non multi tenant, it would help to fix it, if there is a bug in devise invitable not catched with tests, because all tests are passing.

With multi tenant, you may add some log to ensure right database is connected, e.g. define self.accept_invitation! in your model:

def self.accept_invitation!(update_resource_params)
  log "#{connection.current_database}"
  super.tap { |resource| log resource.inspect }
end

[rks92]

@scambra I apologize. I forgot to change the @resource.token to @token when I upgraded the versions and that's why I was facing the issue. Once changed it worked perfectly.