3

I have a Rails 4 app with Devise 3.2.2 using :confirmable, and am running into an issue with it sending invalid confirmation tokens, but only the first time. After you resend the confirmation token, the link works.

The relevant routes:

devise_for :users, skip: [:sessions, :passwords, :confirmations, :unlocks, :registrations, :invitations]
as :user do
  ...
  # joining
  get   '/register' => 'devise/registrations#new',    as: 'new_user_registration'
  post  '/register' => 'devise/registrations#create', as: 'user_registration'
  ...
end

...and the mail template in question:

<p>Welcome <%= @email %>!</p>

<p>You can confirm your account email through the link below:</p>

<p><%= link_to 'Confirm my account', confirmation_url(@resource, :confirmation_token => @token) %></p>

As far as I can tell, everything is pretty standard fare, and the fact that it only fails when initially creating and not on the resend is rather confusing.

--Update--

When clicking on the link, I get the following in my dev log:

Started GET "/account/confirm?confirmation_token=3bQP-EvYJPv74s9AMz63" for 127.0.0.1 at 2014-02-07 12:26:10 -0500
Processing by Users::ConfirmationsController#show as HTML
  Parameters: {"confirmation_token"=>"3bQP-EvYJPv74s9AMz63"}
  User Load (0.4ms)  SELECT "users".* FROM "users" WHERE "users"."confirmation_token" = 'e191b48746f15014beb32073f08de3c7aa13a2282216f089fa71d083901b3dca' ORDER BY "users"."id" ASC LIMIT 1
  Rendered devise/shared/_links.slim (1.2ms)
  Rendered devise/confirmations/new.html.slim within layouts/devise (7.0ms)
  Rendered layouts/_jquery.slim (1.0ms)
Completed 200 OK in 32ms (Views: 23.4ms | ActiveRecord: 0.4ms)

The referenced controller is:

class Users::ConfirmationsController < Devise::ConfirmationsController

  protected

  def after_confirmation_path_for(resource_name, resource)
    if signed_in?
      signed_in_root_path(resource)
    else
      new_session_path(resource_name, email: resource.email)
    end
  end

end

-- Update 2 --

The following is a gist of the logs from the entire signup process: https://gist.github.com/jbender/bbe079c2dd3fa2d1e664

Jonathan Bender
  • 1,911
  • 4
  • 22
  • 39
  • As per the dev log, the status says `Completed 200 OK` so i am assuming that this log is for the resend confirmation from the `Users::ConfirmationsController#show` action. Can you share the confirmation email token link content generated first time and then the log upon clicking the same so that we can analyze the data. – Kirti Thorat Feb 07 '14 at 23:32
  • Nope, that's the log from the first attempt (that fails). The posted log message results in a the 'invalid token' error being shown even though it was a 200 status. – Jonathan Bender Feb 09 '14 at 21:03

2 Answers2

6

It looks like there's something which is causing your user to be immediately updated and resaved (including generation of a new confirmation token) before the registration create action has finished. Looking at your gist:

  • Line 5 shows devise checking for existing users with the email address
  • Line 6 shows devise checking whether the confirmation token it has just generated already exists for some other user (obviously they need to be unique)
  • Line 9 shows the new user record being inserted into your database
  • Line 11 then looks like devise has just generated a new confirmation token and is checking whether this new token is in use already.
  • Line 14 then shows updated user details being saved, including this new confirmation token. I notice that there is a tos_accepted_at field which wasn't present in the initial insert in line 9. The unconfirmed_email field has also been set and the confirmation_sent_at field is 1 second later than the one saved in line 9; this is probably just due to the normal :confirmable behaviour, though I'm surprised devise didn't catch the fact that the email address was the same as the existing (unconfirmed) one and not bother.

The question is why did the user get saved twice? It looks like you've added a tos_accepted_at attribute. Is there some code somewhere (an after filter?) resaving the user including this attribute, along with all the others, which then triggers devise's confirmable logic again? Speaking of which, I'm most intrigued that it didn't immediately cause a second email to be sent (with a confirmation token that works), given that the confirmation_sent_at timestamp changes.

I notice that there's some version tracking going on too, judging by other INSERTs, though it doesn't look like that can be interfering.

As an additional sanity check, if you could bludgeon the rails console into encrypting what you expect the confirmation token to be, you'd find that the encrypted version matches the version at line 6 of your gist, which is then overwritten in the db at line 9. I can't try this, because it depends on your rails secret (see Devise::TokenGenerator in devise/toekn_generator.rb). Anyway, not necessary, but would confirm that the original confirmation token is never going to work.

I assume the resend works because it's just the normal case (no double save, no extra tos_accepted_at field etc.)

UPDATE

As discussed in the comments, the problem was indeed the tos_accepted_at attribute. It was being updated using update_attribute() in an after_create callback. For reasons which are a bit unclear, this seemed to be dirtying all attributes, so they were all saved as well (update_attribute also saves all other attributes if they're dirty) and devise generated a new confirmation token as part of this process (though we don't think it should have as the email address hadn't actually changed!). Changing your filter which saved the updated tos_accepted_at to a before_save filter instead of after_create avoided the problem by making sure the user was only saved once, because before_save obviously happens before that first save as opposed to after_create which of course happens after the save which inserts the user into the db.

Tim
  • 2,903
  • 2
  • 18
  • 16
  • There is a validation of the `tos_agreement` on create, as well as an `after_create` to update it (users are invitable, so it's only set if they signed up themselves), but that's just a `self.update_attribute(:tos_accepted_at, Time.now)` call if a condition is met, which I wouldn't think would trigger a resave of the entire object? – Jonathan Bender Feb 21 '14 at 01:06
  • 1
    You'd think it wouldn't, but it seems if AR thinks other attributes are dirty, it'll update them too. It only really skips validations - see http://apidock.com/rails/ActiveRecord/Persistence/update_attribute for more. I don't know _why_ it would think other attributes are dirty, but perhaps that's what's happening. How about being slightly underhand and trying `self.update_column(:tos_accepted_at, Time.now)` instead of `update_attribute` which looks like it'll skip everything except updating that precise column directly? That should at least rule out or confirm this as the culprit. – Tim Feb 21 '14 at 09:46
  • …and/or try just disabling the filter (along with any other added ones). – Tim Feb 21 '14 at 09:54
  • This ended up being the issue. By calling `update_tos_agreement` "after_validation", it worked as expected. Could you update your answer to reflect the true cause (why it's regening the `confirmation_token` after every save pre-acceptance is another question altogether) and I'll award the bounty? – Jonathan Bender Feb 22 '14 at 04:03
  • Excellent; I'm glad it's resolved. I've updated the answer with what we've discussed in the comments, preserving the rest of the answer in case other bits are useful to others (I know edits can be viewed, but I doubt many people dig through history). However, something occurred to me: if it's an `after_validation` filter, is the `tos_accepted_at` attribute now being updated every time the user is changed (which you presumably wouldn't want), or does the filter method check whether it's already set before setting it? – Tim Feb 22 '14 at 12:51
  • 1
    I ended up making it a `before_save` as having it as an `after_validation` prevented the validation errors from coming through. That being said, it's a conditional validation (ToS might be updated and they'd need to accept again). – Jonathan Bender Feb 22 '14 at 16:06
-1

Based on the routes file, I am assuming you have overridden registrations controller.
My hunch is that you have done something improperly in your registrations#create action. Specifically, the confirmation_token is not being stored properly in the User record when it is created.

My theory is:

  1. Line 278 of confirmable.rb is returning false because line 277 is not finding a user with the supplied token because it wasn't stored properly. 277 thus creates a new user record and 278 returns false.

  2. When you go through the resend process, the whole token generation/storage process is done over again a la confirmable.rb and confirmations#create in confirmations_controller.rb. This fixes the missed storage step in registrations#create.

Can you verify that the confirmation_token is being stored properly on your user model upon initial creation?

Michael Pell
  • 1,416
  • 1
  • 14
  • 17
  • 1) I'm not overriding the registrations controller, just changing the path (they're still going to `devise/registrations#create`) 2) The user is being saved properly, and contains the token as expected: `#` – Jonathan Bender Feb 07 '14 at 19:39