Rails won't save to database after tiny model manipulation

I'm coding my first Rails app at the moment and can't resolve this annoying error.

What I want to do: The app is connected to a user's dropbox account. The user can specify a path in which the app then looks for audio files. These audio files shall then be downloaded, the metadata, path, etc saved to a Song model in the database, which belongs_to the corresponding user.

I implemented a method that indexes the dropbox folder and saves the filename and the direct link already a few weeks ago. Now I added a line that saves the entire dropbox path to the database as well and all of a sudden nothing is saved anymore.

This is what my song model looks like:

require "dropbox_helper"
require "open-uri"

class Song < ActiveRecord::Base
  belongs_to :user
  attr_accessible :artist, :expiration, :is_cached, :length, :dropbox_link, :local_path, :title, :dropbox_path

  validates_presence_of :title, :is_cached, :dropbox_link, :dropbox_path
  #validates :dropbox_path, :uniqueness => true

  def self.fetch_basic_songdata(user)
    logger.info "++++DEBUG: Song#fetch_basic_songdata started"
    dbh = DropboxHelper.new(user.dropbox_access_key, user.dropbox_access_secret, user.dropbox_folder)
    logger.info "++++DEBUG: DropboxHelper initialized"
    songs_metadata = dbh.generate_audio_index
    logger.info "++++DEBUG: Metadata generated"
    #logger.debug songs_metadata.inspect
    songs_metadata.each do |smd|
      logger.info "Preparing song #{smd['path']} for saving"
      songdata = dbh.song_data(smd)
      user.songs.create do |s|
        s.title = songdata['filename']
        s.dropbox_path = songdata['path']
        s.dropbox_link = songdata['link']
        s.is_cached = false
        logger.info "Song #{s[:title]} generated"
        logger.info "Song #{s[:title]} saved to the data base"
      end
    end
  end

end

Now when I call Song.fetch_basic_songdata(User.find(1)) in the rails console, it prints the following:

irb(main):002:0> Song.fetch_basic_songdata(User.find(1))
  User Load (59.4ms)  SELECT "users".* FROM "users" WHERE "users"."id" = ? LIMIT 1  [["id", 1]]
Song#fetch_basic_songdata started
Preparing song /audiomixer/01 - Paradise.mp3 for saving
   (0.1ms)  begin transaction
Song 01 - Paradise.mp3 generated
Song 01 - Paradise.mp3 saved to the data base
   (0.1ms)  commit transaction
Preparing song /audiomixer/02 - Weirdo.mp3 for saving
   (0.1ms)  begin transaction
Song 02 - Weirdo.mp3 generated
Song 02 - Weirdo.mp3 saved to the data base
   (0.2ms)  commit transaction
Preparing song /audiomixer/03 - As It Is When It Was.mp3 for saving
   (0.1ms)  begin transaction
Song 03 - As It Is When It Was.mp3 generated
Song 03 - As It Is When It Was.mp3 saved to the data base
   (0.1ms)  commit transaction
Preparing song /audiomixer/04 - Broken Promise.mp3 for saving
   (0.2ms)  begin transaction
Song 04 - Broken Promise.mp3 generated
Song 04 - Broken Promise.mp3 saved to the data base
   (0.1ms)  commit transaction
Preparing song /audiomixer/05 - Way Of Life.mp3 for saving
   (0.1ms)  begin transaction
Song 05 - Way Of Life.mp3 generated
Song 05 - Way Of Life.mp3 saved to the data base
   (0.1ms)  commit transaction
Preparing song /audiomixer/06 - Bizarre Love Triangle.mp3 for saving
   (0.1ms)  begin transaction
Song 06 - Bizarre Love Triangle.mp3 generated
Song 06 - Bizarre Love Triangle.mp3 saved to the data base
   (0.1ms)  commit transaction
Preparing song /audiomixer/07 - All Day Long.mp3 for saving
   (0.1ms)  begin transaction
Song 07 - All Day Long.mp3 generated
Song 07 - All Day Long.mp3 saved to the data base
   (0.1ms)  commit transaction
Preparing song /audiomixer/08 - Angel Dust.mp3 for saving
   (0.1ms)  begin transaction
Song 08 - Angel Dust.mp3 generated
Song 08 - Angel Dust.mp3 saved to the data base
   (0.1ms)  commit transaction
Preparing song /audiomixer/09 - Every Little Counts.mp3 for saving
   (0.1ms)  begin transaction
Song 09 - Every Little Counts.mp3 generated
Song 09 - Every Little Counts.mp3 saved to the data base
   (0.1ms)  commit transaction
Preparing song /audiomixer/10 - State Of The Nation.mp3 for saving
   (0.1ms)  begin transaction
Song 10 - State Of The Nation.mp3 generated
Song 10 - State Of The Nation.mp3 saved to the data base
   (0.0ms)  commit transaction
=> [#<Dropbox::API::File bytes=3710598 client_mtime="Fri, 23 Jul 2010 00:09:30 +0000" icon="page_white_sound" is_dir=false mime_type="audio/mpeg" modified="Mon, 22 Apr 2013 12:27:54 +0000" path="/audiomixer/01 - Paradise.mp3" rev="4b6ad8fc0010df0f" revision=1265293564 root="dropbox" size="3.5 MB" thumb_exists=false>, #<Dropbox::API::File bytes=3731496 client_mtime="Fri, 23 Jul 2010 00:09:30 +0000" icon="page_white_sound" is_dir=false mime_type="audio/mpeg" modified="Mon, 22 Apr 2013 12:27:54 +0000" path="/audiomixer/02 - Weirdo.mp3" rev="4b6ad8fd0010df0f" revision=1265293565 root="dropbox" size="3.6 MB" thumb_exists=false>, #<Dropbox::API::File bytes=3620319 client_mtime="Sun, 10 Jan 2010 19:50:28 +0000" icon="page_white_sound" is_dir=false mime_type="audio/mpeg" modified="Mon, 22 Apr 2013 12:27:54 +0000" path="/audiomixer/03 - As It Is When It Was.mp3" rev="4b6ad8fa0010df0f" revision=1265293562 root="dropbox" size="3.5 MB" thumb_exists=false>, #<Dropbox::API::File bytes=3645815 client_mtime="Sun, 10 Jan 2010 19:50:28 +0000" icon="page_white_sound" is_dir=false mime_type="audio/mpeg" modified="Mon, 22 Apr 2013 12:27:54 +0000" path="/audiomixer/04 - Broken Promise.mp3" rev="4b6ad8fb0010df0f" revision=1265293563 root="dropbox" size="3.5 MB" thumb_exists=false>, #<Dropbox::API::File bytes=3954295 client_mtime="Sat, 20 Apr 2013 07:09:30 +0000" icon="page_white_sound" is_dir=false mime_type="audio/mpeg" modified="Mon, 22 Apr 2013 12:27:54 +0000" path="/audiomixer/05 - Way Of Life.mp3" rev="4b6ad8fe0010df0f" revision=1265293566 root="dropbox" size="3.8 MB" thumb_exists=false>, #<Dropbox::API::File bytes=4199193 client_mtime="Sun, 10 Jan 2010 19:50:28 +0000" icon="page_white_sound" is_dir=false mime_type="audio/mpeg" modified="Mon, 22 Apr 2013 12:27:54 +0000" path="/audiomixer/06 - Bizarre Love Triangle.mp3" rev="4b6ad8ff0010df0f" revision=1265293567 root="dropbox" size="4 MB" thumb_exists=false>, #<Dropbox::API::File bytes=5002092 client_mtime="Sun, 10 Jan 2010 19:50:28 +0000" icon="page_white_sound" is_dir=false mime_type="audio/mpeg" modified="Mon, 22 Apr 2013 12:27:54 +0000" path="/audiomixer/07 - All Day Long.mp3" rev="4b6ad9010010df0f" revision=1265293569 root="dropbox" size="4.8 MB" thumb_exists=false>, #<Dropbox::API::File bytes=3595686 client_mtime="Sat, 20 Apr 2013 07:09:31 +0000" icon="page_white_sound" is_dir=false mime_type="audio/mpeg" modified="Mon, 22 Apr 2013 12:27:54 +0000" path="/audiomixer/08 - Angel Dust.mp3" rev="4b6ad8f90010df0f" revision=1265293561 root="dropbox" size="3.4 MB" thumb_exists=false>, #<Dropbox::API::File bytes=4307888 client_mtime="Sat, 20 Apr 2013 07:09:32 +0000" icon="page_white_sound" is_dir=false mime_type="audio/mpeg" modified="Mon, 22 Apr 2013 12:27:54 +0000" path="/audiomixer/09 - Every Little Counts.mp3" rev="4b6ad9000010df0f" revision=1265293568 root="dropbox" size="4.1 MB" thumb_exists=false>, #<Dropbox::API::File bytes=6313648 client_mtime="Sun, 10 Jan 2010 19:50:28 +0000" icon="page_white_sound" is_dir=false mime_type="audio/mpeg" modified="Mon, 22 Apr 2013 12:27:54 +0000" path="/audiomixer/10 - State Of The Nation.mp3" rev="4b6ad9020010df0f" revision=1265293570 root="dropbox" size="6 MB" thumb_exists=false>]

To check if anything is saved:

irb(main):003:0> Song.all
  Song Load (0.3ms)  SELECT "songs".* FROM "songs" 
=> []

I also noticed that the lines starting with logger.info "++++DEBUG:[...]" are not printed at all. Before I inserted them, the logger.info lines below weren't printed. I really don't get that behaviour, can anyone of you help?

PS: I hope the information provided is sufficient. As the app's behaviour is totally random to me, I have a hard time understanding what's essential to the problem.

edit: Thanks for the comments! As recommended, I tried using create!. This is what it told me:

irb(main):002:0> Song.fetch_basic_songdata(User.find(1))
  User Load (0.1ms)  SELECT "users".* FROM "users" WHERE "users"."id" = ? LIMIT 1  [["id", 1]]
++++DEBUG: Song#fetch_basic_songdata started
++++DEBUG: DropboxHelper initialized
++++DEBUG: Metadata generated
Preparing song /audiomixer/01 - Paradise.mp3 for saving
   (0.1ms)  begin transaction
Song 01 - Paradise.mp3 generated
Song 01 - Paradise.mp3 saved to the data base
   (0.2ms)  rollback transaction
ActiveRecord::RecordInvalid: Validation failed: Is cached can't be blank
    from /var/lib/gems/1.9.1/gems/activerecord-3.2.13/lib/active_record/validations.rb:56:in `save!'
    from /var/lib/gems/1.9.1/gems/activerecord-3.2.13/lib/active_record/attribute_methods/dirty.rb:33:in `save!'
    from /var/lib/gems/1.9.1/gems/activerecord-3.2.13/lib/active_record/transactions.rb:264:in `block in save!'
    from /var/lib/gems/1.9.1/gems/activerecord-3.2.13/lib/active_record/transactions.rb:313:in `block in with_transaction_returning_status'
    from /var/lib/gems/1.9.1/gems/activerecord-3.2.13/lib/active_record/connection_adapters/abstract/database_statements.rb:192:in `transaction'
    from /var/lib/gems/1.9.1/gems/activerecord-3.2.13/lib/active_record/transactions.rb:208:in `transaction'
    from /var/lib/gems/1.9.1/gems/activerecord-3.2.13/lib/active_record/transactions.rb:311:in `with_transaction_returning_status'
    from /var/lib/gems/1.9.1/gems/activerecord-3.2.13/lib/active_record/transactions.rb:264:in `save!'
    from /var/lib/gems/1.9.1/gems/activerecord-3.2.13/lib/active_record/associations/has_many_association.rb:14:in `insert_record'
    from /var/lib/gems/1.9.1/gems/activerecord-3.2.13/lib/active_record/associations/collection_association.rb:436:in `block (2 levels) in create_record'
    from /var/lib/gems/1.9.1/gems/activerecord-3.2.13/lib/active_record/associations/collection_association.rb:344:in `add_to_target'
    from /var/lib/gems/1.9.1/gems/activerecord-3.2.13/lib/active_record/associations/collection_association.rb:434:in `block in create_record'
    from /var/lib/gems/1.9.1/gems/activerecord-3.2.13/lib/active_record/associations/collection_association.rb:149:in `block in transaction'
    from /var/lib/gems/1.9.1/gems/activerecord-3.2.13/lib/active_record/connection_adapters/abstract/database_statements.rb:192:in `transaction'
    from /var/lib/gems/1.9.1/gems/activerecord-3.2.13/lib/active_record/transactions.rb:208:in `transaction'
    from /var/lib/gems/1.9.1/gems/activerecord-3.2.13/lib/active_record/associations/collection_association.rb:148:in `transaction'
    from /var/lib/gems/1.9.1/gems/activerecord-3.2.13/lib/active_record/associations/collection_association.rb:433:in `create_record'
    from /var/lib/gems/1.9.1/gems/activerecord-3.2.13/lib/active_record/associations/collection_association.rb:123:in `create!'
    from /var/lib/gems/1.9.1/gems/activerecord-3.2.13/lib/active_record/associations/collection_proxy.rb:46:in `create!'
    from /home/sloth/audiomixer/app/models/song.rb:21:in `block in fetch_basic_songdata'
    from /home/sloth/audiomixer/app/models/song.rb:18:in `each'
    from /home/sloth/audiomixer/app/models/song.rb:18:in `fetch_basic_songdata'
    from (irb):2
    from /var/lib/gems/1.9.1/gems/railties-3.2.13/lib/rails/commands/console.rb:47:in `start'
    from /var/lib/gems/1.9.1/gems/railties-3.2.13/lib/rails/commands/console.rb:8:in `start'
    from /var/lib/gems/1.9.1/gems/railties-3.2.13/lib/rails/commands.rb:41:in `<top (required)>'
    from script/rails:6:in `require'
    from script/rails:6:in `

So if I interpreted this correctly, the problem is that the is_cached variable appears to be blank (empty? nil?). I assume this being due to an error happening before the s.is_cached = false assignment. Any ideas how to find it?

Besides, I just commented some of the logger.info lines and added new ones instead. After I restarted the server, I tried again and it printed the lines I commented but none of the new ones. Do I lack some very important information about Rails using old files? I've been doing the same things during the last weeks and never experienced any such weird experience.

Answers


You shouldn't use validates_presence_of with boolean attributes because it checks that the attribute is present by calling the blank? method. However, false.blank? is true, so it will never let you save a record when the attribute is false.

You may also want to note that the rails console doesn't automatically pick changes you make to your code. You need to either call reload! or restart the console. When using reload!, be careful that you don't have instances of objects created before the call to reload! hanging around - they may be referring to the previous version of the class.


Need Your Help

What is the difference between pickle and shelve?

python object pickle shelve object-serialization

I am learning about object serialization for the first time. I tried reading and 'googling' for differences in the modules pickle and shelve but I am not sure I understand it. When to use which one?

About UNIX Resources Network

Original, collect and organize Developers related documents, information and materials, contains jQuery, Html, CSS, MySQL, .NET, ASP.NET, SQL, objective-c, iPhone, Ruby on Rails, C, SQL Server, Ruby, Arrays, Regex, ASP.NET MVC, WPF, XML, Ajax, DataBase, and so on.