Diagnosing Rails Application Hang on Element Update

Question

In the course of building a rails application to help small hotels' manage bookings, I'm encountering a strange application hang. Building the reservation works fine; adding guests, assigning them to rooms, etc, without issue. However, when the merchant goes to 'confirm' an inquiry, Mongrel hangs me out to dry.

The index page for reservations lists the current inquiries and confirmed bookings:

# reservations/index.html.erb

<% unless @reservations.empty? %>
<h2>Inquiries</h2><hr/><br/>
<%= render :partial => 'reservation', :collection => @reservations.reject { |r| r.confirmed } %>
<h2>Confirmed Reservations</h2><hr/><br/>
<%= render :partial => 'reservation', :collection => @reservations.reject { |r| not r.confirmed }  %>
<% else %>
<%= link_to 'Search for rooms', :action => 'index', :controller => 'search' %>
<% end %>

In the reservation partial itself, the bits which invoke the confirm/unconfirm logic are simply direct links to controller actions:

# _reservation.html.erb

(<% unless reservation.confirmed? %>
    <%= link_to 'Confirm Reservation', :action => 'confirm', :id => reservation.id %>
<% else %>
    <%= link_to 'Unconfirm Reservation', :action => 'unconfirm', :id => reservation.id %>
<% end %>)

The controller action to confirm a reservation, which is mapped to a PUT in my routes, looks like this:

def confirm
  puts "\n\n\nConfirming reservation #{params[:id]}..."
  @reservation = Reservation.find(params[:id])
  puts "Found reservation! Confirming..."
  @reservation[:confirmed] = true
  puts "Confirmed, saving..."
  respond_to do |wants|            
    if @reservation.save
      flash[:notice] = 'Reservation has been confirmed.'
      wants.html { redirect_to :action => 'index' }
    else
      wants.html { render :action => 'index' }
    end
  end    
end

'@reservation.save' is what does the trick. Definite app hang every time.

Can someone help me understand just what is going on here?

/UPDATE:

From playing around with the console I was able to demonstrate the issue in another way:

?> r = Reservation.find(36)
=> #<Reservation id: 36, customer_name: "buyer", customer_email: "[email protected]", begin: "2009-06-22 00:00:00", end: "2009-06-26 00:00:00", request_timestamp: nil, notes: "Thanks!", created_at: "2009-06-13 20:36:50", updated_at: "2009-06-13 20:36:50", yacht_id: 7, adults: 1, children: 0, buyer_id: 3, confirmed: nil>
>> r.confirmed = true
=> true
>> r
=> #<Reservation id: 36, customer_name: "buyer", customer_email: "[email protected]", begin: "2009-06-22 00:00:00", end: "2009-06-26 00:00:00", request_timestamp: nil, notes: "Thanks!", created_at: "2009-06-13 20:36:50", updated_at: "2009-06-13 20:36:50", yacht_id: 7, adults: 1, children: 0, buyer_id: 3, confirmed: true>
>> r.save!
IRB::Abort: abort then interrupt!!
    from C:/Ruby/lib/ruby/1.8/irb.rb:81:in `irb_abort'
    from C:/Ruby/lib/ruby/1.8/irb.rb:247:in `signal_handle'
    from C:/Ruby/lib/ruby/1.8/irb.rb:66:in `start'
    from C:/Ruby/lib/ruby/gems/1.8/gems/activesupport-2.3.2/lib/active_support/callbacks.rb:275:in `call'
    from C:/Ruby/lib/ruby/gems/1.8/gems/activesupport-2.3.2/lib/active_support/callbacks.rb:275:in `run_callbacks'
    from C:/Ruby/lib/ruby/gems/1.8/gems/activerecord-2.3.2/lib/active_record/callbacks.rb:344:in `callback'
    from C:/Ruby/lib/ruby/gems/1.8/gems/activerecord-2.3.2/lib/active_record/callbacks.rb:318:in `valid?'
    from C:/Ruby/lib/ruby/gems/1.8/gems/activerecord-2.3.2/lib/active_record/associations/association_proxy.rb:221:in `send'
    from C:/Ruby/lib/ruby/gems/1.8/gems/activerecord-2.3.2/lib/active_record/associations/association_proxy.rb:221:in `method_missing'
    from C:/Ruby/lib/ruby/gems/1.8/gems/activerecord-2.3.2/lib/active_record/validations.rb:906:in `validates_associated'
    from C:/Ruby/lib/ruby/gems/1.8/gems/activerecord-2.3.2/lib/active_record/validations.rb:906:in `collect'
    from C:/Ruby/lib/ruby/gems/1.8/gems/activerecord-2.3.2/lib/active_record/validations.rb:906:in `validates_associated'
    from C:/Ruby/lib/ruby/gems/1.8/gems/activerecord-2.3.2/lib/active_record/validations.rb:399:in `validates_each'
    from C:/Ruby/lib/ruby/gems/1.8/gems/activerecord-2.3.2/lib/active_record/validations.rb:396:in `each'
    from C:/Ruby/lib/ruby/gems/1.8/gems/activerecord-2.3.2/lib/active_record/validations.rb:396:in `validates_each'
    from C:/Ruby/lib/ruby/gems/1.8/gems/activesupport-2.3.2/lib/active_support/callbacks.rb:182:in `call'
 ... 2204 levels...
    from C:/Ruby/lib/ruby/gems/1.8/gems/activesupport-2.3.2/lib/active_support/callbacks.rb:90:in `run'
    from C:/Ruby/lib/ruby/gems/1.8/gems/activesupport-2.3.2/lib/active_support/callbacks.rb:90:in `each'
    from C:/Ruby/lib/ruby/gems/1.8/gems/activesupport-2.3.2/lib/active_support/callbacks.rb:90:in `send'
    from C:/Ruby/lib/ruby/gems/1.8/gems/activesupport-2.3.2/lib/active_support/callbacks.rb:90:in `run'
    from C:/Ruby/lib/ruby/gems/1.8/gems/activesupport-2.3.2/lib/active_support/callbacks.rb:276:in `run_callbacks'
    from C:/Ruby/lib/ruby/gems/1.8/gems/activerecord-2.3.2/lib/active_record/validations.rb:1029:in `valid_without_callbacks?'
    from C:/Ruby/lib/ruby/gems/1.8/gems/activerecord-2.3.2/lib/active_record/callbacks.rb:315:in `valid?'
    from C:/Ruby/lib/ruby/gems/1.8/gems/activerecord-2.3.2/lib/active_record/validations.rb:1018:in `save_without_dirty!'
    from C:/Ruby/lib/ruby/gems/1.8/gems/activerecord-2.3.2/lib/active_record/dirty.rb:87:in `save_without_transactions!'
    from C:/Ruby/lib/ruby/gems/1.8/gems/activerecord-2.3.2/lib/active_record/transactions.rb:200:in `save!'
    from C:/Ruby/lib/ruby/gems/1.8/gems/activerecord-2.3.2/lib/active_record/connection_adapters/abstract/database_statements.rb:136:in `transaction'
    from C:/Ruby/lib/ruby/gems/1.8/gems/activerecord-2.3.2/lib/active_record/transactions.rb:182:in `transaction'
    from C:/Ruby/lib/ruby/gems/1.8/gems/activerecord-2.3.2/lib/active_record/transactions.rb:200:in `save!'
    from C:/Ruby/lib/ruby/gems/1.8/gems/activerecord-2.3.2/lib/active_record/transactions.rb:208:in `rollback_active_record_state!'
    from C:/Ruby/lib/ruby/gems/1.8/gems/activerecord-2.3.2/lib/active_record/transactions.rb:200:in `save!'
    from (irb):5>>

Note that the console locked up as well, and I had to abort the save! command using Ctrl-C.

Why in the world would the save! be doing this?

/UPDATE:

Got it!!! It was in my model. I was trying to validate an association and I had gotten the has_many/belongs_to stuff backwards.

Thanks, everyone!

Answer 1

Use thin instead of mongrel. Post more details from your log. It doesn't just hang like that usually.

Answer 2

Your issue may be this:

@reservation[:confirmed] = true

You're directly updating the attributes hash, which is a little odd. Normally, you'd just update the attribute.

@reservation.confirmed = true

I've had odd issues before when I messed with the attribute hash. Booleans especially - maybe because there is some type coercion happening.