3

I have a Devise registration form that is submitting twice when I press the submit button. Initially, I thought the issue was turbolinks, but I tried disabling it and the server logs still shows Users::RegistrationsController#create getting hit twice.

<%= form_for(resource, :as => resource_name, :url => registration_path(resource_name), html: {class: 'form-signin', role: 'form'}) do |f| %>
  <%= devise_error_messages! %>
  <% if current_or_guest_user.present? %>
    <%= f.text_field :name, :autofocus => true, :class => 'form-control', :placeholder => 'Full Name', :value => current_or_guest_user.name %>
    <%= f.email_field :email, :class => 'form-control', :placeholder => 'Email Address', :value => current_or_guest_user.unconfirmed_email %>
    <%= f.text_field :postal_code, :autofocus => true, :class => 'form-control', :placeholder => 'Zip Code', :value => current_or_guest_user.postal_code %>
  <% end %>
  <%= f.submit 'Sign Up', class: 'btn btn-lg btn-primary btn-block } %>
<% end %>

The odd thing is that if I add a puts "COW into my controller action, I only see it get outputted once in the server logs. However, there are two different time stamps that calls the controller so I'm confident it's getting called twice.

def create
  puts "COW!!!"
  if current_or_guest_user
    current_or_guest_user.update_attributes(name: params[:user][:name], email: params[:user][:email], postal_code: params[:user][:postal_code]) if (current_or_guest_user.pseudo? || current_or_guest_user.guest?)
    redirect_to service_region_path(current_or_guest_user.current_service_region.url_name), notice: "Please check your email for a confirmation link to complete your registration" and return
  else
    super
  end
end

Server output

I, [2014-06-11T19:38:19.043603 #8159]  INFO -- : Started POST "/users" for 127.0.0.1 at 2014-06-11 19:38:19 -0700
I, [2014-06-11T19:38:19.043629 #8159]  INFO -- : Started POST "/users" for 127.0.0.1 at 2014-06-11 19:38:19 -0700
I, [2014-06-11T19:38:19.049479 #8159]  INFO -- : Processing by Users::RegistrationsController#create as HTML
I, [2014-06-11T19:38:19.049536 #8159]  INFO -- : Processing by Users::RegistrationsController#create as HTML
I, [2014-06-11T19:38:19.049571 #8159]  INFO -- :   Parameters: {"utf8"=>"✓", "authenticity_token"=>"4a/sJWkOtfQxaPmpnvcAYU/77mRwIDaC4bEFMvlfyHQ=", "user"=>{"name"=>"mh", "email"=>"jj@h.com", "postal_code"=>"94103"}, "commit"=>"Sign Up"}
I, [2014-06-11T19:38:19.049586 #8159]  INFO -- :   Parameters: {"utf8"=>"✓", "authenticity_token"=>"4a/sJWkOtfQxaPmpnvcAYU/77mRwIDaC4bEFMvlfyHQ=", "user"=>{"name"=>"mh", "email"=>"jj@h.com", "postal_code"=>"94103"}, "commit"=>"Sign Up"}
COW!!!
D, [2014-06-11T19:38:19.057844 #8159] DEBUG -- :   User Load (6.4ms)  SELECT  "users".* FROM "users"  WHERE "users"."id" = $1 LIMIT 1  [["id", 37569]]
D, [2014-06-11T19:38:19.057951 #8159] DEBUG -- :   User Load (6.4ms)  SELECT  "users".* FROM "users"  WHERE "users"."id" = $1 LIMIT 1  [["id", 37569]]

My guess is that there might be some javascript that is submitting the form when I press submit, but I haven't written any custom javascript to target my forms.

application.js

//= require jquery
//= require jquery_ujs
//= require turbolinks
//= require twitter/bootstrap
//= require bootstrap-select
//= require moment
//= require bootstrap-datetimepicker
//= require jquery.payment
//= require zeroclipboard
//= require_tree .

Do you guys have any tips on how I can dig into this issue further - how do I figure out what could possibly be making the 2nd call? I want to find the root cause of the problem and not have to patch it using some javascript to disable the form after first submission.

Huy
  • 10,806
  • 13
  • 55
  • 99
  • It looks like somehow logger is logging twice. If the form was submitted twice then obviously `COW!!!` would be printed twice. And also, the requests would be one after another not going simultaneously. The lag between the log messages seems like just the printing lag. Have you made any changes related to Rails Logger configuration? Or Have you added a new gem in your application? – Kirti Thorat Jun 12 '14 at 15:41
  • 1
    If you have `rails_12factor gem` then make sure its placed under `production` group, as there seems to be a bug in it. Read http://stackoverflow.com/questions/19900093/rails-logger-appears-to-be-duplicating-log-lines – Kirti Thorat Jun 12 '14 at 15:44
  • @KirtiThorat my `rails_12factor` gem is already placed in production. Initially, I thought it was the logger just printing log messages twice, but the timestamp lead me to believe that there are two actual calls to the server. – Huy Jun 12 '14 at 16:16
  • 1
    I still think its logging related. There will be a lag in printing the logs, two lags wouldn't be printed exactly at the same time. Also, whenever I have come across double request problems associated with `turbolinks`, its like the first request is completed successfully first and then the duplicate request is started, *like one after another* and not *simultaneously* (Like what is happening in your case). – Kirti Thorat Jun 12 '14 at 16:55
  • @KirtiThorat I think you are right. If I use foreman, the server logs only output once, but if I use rails server, it outputs twice. – Huy Jun 12 '14 at 17:26

1 Answers1

1

Strange issue - the best thing I can suggest is it might be a turbolinks issue

The way to test this will either be to remove Turbolinks from your app for the time being, or to disable turbolinks explicitly on your form. If this works, it will generally mean you have a setting / argument somewhere which will be triggering the turbolinks activity:

#application.js
//= require jquery
//= require jquery_ujs
//= require turbolinks <- remove
//= require twitter/bootstrap
//= require bootstrap-select
//= require moment
//= require bootstrap-datetimepicker
//= require jquery.payment
//= require zeroclipboard
//= require_tree .

#app/views/layouts/application.html.erb
stylesheet_link_tag    "application", media: "all"

#app/views/devise/registrations/new.html.erb
<%= form_for(resource, :as => resource_name, :url => registration_path(resource_name), html: {class: 'form-signin', role: 'form'}, data: { no_turbolink: true }) do |f| %>
Community
  • 1
  • 1
Richard Peck
  • 76,116
  • 9
  • 93
  • 147
  • 1
    Yes you are right I have same issue, after removing `//= require turbolinks` it works fine – user2622247 Jun 12 '14 at 07:07
  • 1
    @Rich Peck I tried doing this too. This was my initial thought since I've ran into this problem before. I disabled turbolinks, but the problem still persists. – Huy Jun 12 '14 at 16:20
  • @RickPeck My gem was already in the correct place. It turned out to be a logging issue. Rails server was outputting twice. When I switched to foreman, it outputs only once. Thanks for your help. – Huy Jun 12 '14 at 21:51