Postgres create not working after updating to Rails 5.2

Question

I updated from Rails 5.0 to 5.2 and made very few changes, but one thing quit working. repopulateResidResto is called when an address (location) or person is created or updated. It still works on the Rails 5.0 version at Heroku but not on my updated version on my computer. I can see the method is called in the server logs, but nothing is written to the database. Selected from the Heroku logs:

Year Load (3.5ms)  SELECT  "years".* FROM "years" ORDER BY "years"."id" ASC LIMIT $1 OFFSET $2  [["LIMIT", 1000], ["OFFSET", 206]]
Year Load (2.6ms)  SELECT "years".* FROM "years" ORDER BY id OFFSET $1  [["OFFSET", 207]]
Location Load (1.2ms)  SELECT  "locations".* FROM "locations" WHERE "locations"."id" = $1 LIMIT $2  [["id", 62], ["LIMIT", 1]]
Location Load (1.1ms)  SELECT  "locations".* FROM "locations" WHERE "locations"."id" = $1 LIMIT $2  [["id", 2], ["LIMIT", 1]]
 (4.5ms)  BEGIN
   SQL (1.8ms)  INSERT INTO "resto_resid_lines" ("person_id", "resto_date", "resid_date", "title_resto", "title_resid", "resto_name", "created_at", "updated_at", "resto_connection_id", "resid_connection_id", "resto_loc_id", "resid_loc_id", "lat_resto", "long_resto", "resto_address", "resid_address", "mid_date") VALUES ($1, $2, $3, $4, $5, $6, $7, $8, $9, $10, $11, $12, $13, $14, $15, $16, $17) RETURNING "id"  [["person_id", 34], ["resto_date", "1886-09-01"], ["resid_date", "1886-09-01"], ["title_resto", "Co-proprietor"], ["title_resid", "Resident"], ["resto_name", ""], ["created_at", "2019-02-20 05:10:40.148200"], ["updated_at", "2019-02-20 05:10:40.148200"], ["resto_connection_id", 259], ["resid_connection_id", 258], ["resto_loc_id", 2], ["resid_loc_id", 62], ["lat_resto", "34.052265"], ["long_resto", "-118.243408"], ["resto_address", "11 W First St"], ["resid_address", "23 Sepulveda "], ["mid_date", "1886-09-01"]]
    (2.2ms)  COMMIT

The log on on my Mac with Rails 5.2. I imagine the ROLLBACK is a problem, but don't understand what triggers it:

  Year Load (0.3ms)  SELECT  "years".* FROM "years" ORDER BY "years"."id" ASC LIMIT $1 OFFSET $2  [["LIMIT", 1000], ["OFFSET", 206]]
   ↳ app/controllers/application_controller.rb:19
   Year Load (0.4ms)  SELECT "years".* FROM "years" ORDER BY id OFFSET $1  [["OFFSET", 207]]
   ↳ app/controllers/application_controller.rb:47
   Location Load (0.4ms)  SELECT  "locations".* FROM "locations" WHERE "locations"."id" = $1 LIMIT $2  [["id", 62], ["LIMIT", 1]]
   ↳ app/controllers/application_controller.rb:58
   Location Load (0.3ms)  SELECT  "locations".* FROM "locations" WHERE "locations"."id" = $1 LIMIT $2  [["id", 2], ["LIMIT", 1]]
   ↳ app/controllers/application_controller.rb:64
    (0.1ms)  BEGIN
   ↳ app/controllers/application_controller.rb:53
   Person Load (0.1ms)  SELECT  "people".* FROM "people" WHERE "people"."id" = $1 LIMIT $2  [["id", 34], ["LIMIT", 1]]
   ↳ app/controllers/application_controller.rb:53
    (0.1ms)  ROLLBACK
   ↳ app/controllers/application_controller.rb:53
 Scoped order is ignored, it's forced to be batch order.
   Year Load (0.2ms)  SELECT  "years".* FROM "years" ORDER BY "years"."id" ASC LIMIT $1 OFFSET $2  [["LIMIT", 1000], ["OFFSET", 208]]
   ↳ app/controllers/application_controller.rb:19

Line 19 is yearsBelow.find_each do |yearBelow|.

Line 47 is yearsBelow.each do |yearBelow|

Line 58 is :lat_resid => year.location.latitude.

Line 64 is :lat_resto => yearBelow.location.latitude.

Line 53 is the second RestoResidLine.create.

The controller (no changes made while upgrading to Rails 5.2):

class ApplicationController < ActionController::Base
    protect_from_forgery with: :exception
    include SessionsHelper 
    def repopulateResidResto
      timeSpan = 12.months - 1.day # without 1.day pick up a year later, at least in early development
      i = 1
      RestoResidLine.delete_all
      Year.unscope(:order).order('id').find_each do |year|
        if year.resto
          yearsBelow = Year.offset(i).unscope(:order).order('id') # default sort for year is date and without unscope really messes up things, could sort by lots of things, but id seems safe. Year is sorted by date, and we need that to be in the same sort
          yearsBelow.find_each do |yearBelow|
            foo_time =Time.parse(year.year_date.to_s)
            bar_time = Time.parse(yearBelow.year_date.to_s)
            avg = Time.at((foo_time.to_f + bar_time.to_f) / 2)
            avg_date = Date.parse(avg.to_s) # if these dates are different use average for the lines
            if (year.person_id == yearBelow.person_id) and (((yearBelow.year_date - timeSpan)..(yearBelow.year_date + timeSpan)).cover?year.year_date) and (!yearBelow.resto)
              RestoResidLine.create(:person_id           => year.person_id,
                                    :resto_loc_id        => year.location_id,
                                    :resto_name          => year.resto_name,
                                    :resto_date          => year.year_date,
                                    :title_resto         => year.title,
                                    :lat_resto           => year.location.latitude,
                                    :long_resto          => year.location.longitude,
                                    :resto_address       => year.location.address,
                                    :resid_loc_id        => yearBelow.location_id,
                                    :resid_date          => yearBelow.year_date,
                                    :lat_resid           => yearBelow.location.latitude,
                                    :long_resid          => yearBelow.location.longitude,
                                    :resid_address       => yearBelow.location.address,
                                    :title_resid         => yearBelow.title,
                                    :mid_date            => avg_date,
                                    :resto_connection_id => year.id,
                                    :resid_connection_id => yearBelow.id)
            end
          end
        end
        if year.resid
          yearsBelow = Year.offset(i).unscope(:order).order('id')
          yearsBelow.each do |yearBelow|
            foo_time =Time.parse(year.year_date.to_s)
            bar_time = Time.parse(yearBelow.year_date.to_s)
            avg = Time.at((foo_time.to_f + bar_time.to_f) / 2)
            avg_date = Date.parse(avg.to_s) # if these dates are different use average for the lines
            if (year.person_id == yearBelow.person_id) and (((yearBelow.year_date - timeSpan)..(yearBelow.year_date + timeSpan)).cover?year.year_date) and (!yearBelow.resid)
              RestoResidLine.create(:person_id     => yearBelow.person_id,
                                    :resto_loc_id  => yearBelow.location_id,
                                    :resto_name    => yearBelow.resto_name,
                                    :resto_date    => yearBelow.year_date,
                                    :title_resto   => yearBelow.title,
                                    :lat_resid     => year.location.latitude,
                                    :long_resid    => year.location.longitude,
                                    :resid_address => year.location.address,
                                    :resid_loc_id  => year.location_id,
                                    :resid_date    => year.year_date,
                                    :title_resid   => year.title,
                                    :lat_resto     => yearBelow.location.latitude,
                                    :long_resto    => yearBelow.location.longitude,
                                    :resto_address => yearBelow.location.address,
                                    :mid_date            => avg_date,
                                    :resto_connection_id => yearBelow.id,
                                    :resid_connection_id => year.id)
            end # if
          end # yearBelow
        end
        i += 1
      end
    end
  end

Gemfile:

source 'https://rubygems.org'
git_source(:github) do |repo_name|
  repo_name = "#{repo_name}/#{repo_name}" unless repo_name.include?("/")
  "https://github.com/#{repo_name}.git"
end
ruby '2.6.1' 
gem 'rails', '~> 5.2.2'
gem 'puma', '~> 3.0'
source 'https://rails-assets.org' do 
  gem 'rails-assets-rearmed-js' 
end
gem 'pg'
gem 'bootstrap-sass', '~> 3.4.0'
gem 'sassc-rails', '>= 2.0.0' 
gem 'jquery-rails'   
gem 'jquery-ui-rails'
gem 'turbolinks', '~> 5' 
gem 'sdoc', '~> 0.4.0', group: :doc
gem 'bcrypt',                  '~> 3.1.7'
gem 'faker',                   '1.4.2'
gem 'mini_magick',             '4.6.1'
gem 'will_paginate'
gem 'bootstrap-will_paginate', '0.0.10'
gem 'simple_form'
gem 'fuuu'
gem 'geocoder'
gem 'activerecord-postgis-adapter'
gem 'rgeo-geojson' 
gem "fog-aws"
gem 'aws-sdk-s3', '~> 1' 
gem 'carrierwave', '~> 1.0', '< 2.0'
gem 'pg-eyeballs'
gem 'leaflet-rails' 
gem "responders"

group :development, :test do
  gem 'rspec-rails' 
  gem 'database_cleaner'
  gem 'dotenv-rails' 
  gem 'awesome_print' 
  gem 'super_awesome_print'
end

group :development do
  gem 'web-console', '>= 3.3.0'
  gem "better_errors"
  gem 'binding_of_caller' 
  gem 'byebug', platform: :mri 
  gem 'pry-byebug' 
  gem "rails-erd" 
  gem 'annotate'
  gem 'rubocop', require: false 
end

group :production do
end

group :test do
  gem 'minitest-reporters', '1.1.9'
  gem 'guard',              '2.13.0'
  gem 'guard-minitest',     '2.4.4'
  gem 'rails-controller-testing', '0.1.1'
  gem 'simplecov', :require => false
  gem 'capybara'
end

How might I go about debugging this? Or what changes might be affecting this?

Your `create` calls are probably failing, but you're not capturing why. Try changing those to `create!` and see if an errror is raised. And/or capture the result of `create` to a variable and inspect it's Rails errors and validity. — Philip Hallstrom, Feb 23 '19 at 20:27
Thank you. I'll give those a go. It will be a day or two. If those work out it will be easier than what I was going to try to do. — Greg, Feb 24 '19 at 15:51
Decided I'd step back and learn more testing (about time). Also curious what the bang! is meant to do. — Greg, Mar 01 '19 at 00:50
Answering my intermediate question. bang! https://stackoverflow.com/questions/612189/why-are-exclamation-marks-used-in-ruby-methods — Greg, Mar 01 '19 at 00:57

score 0 · Answer 1 · answered May 15 '19 at 17:46

The line config.load_defaults 5.0 in config/application.rb was the cause of the problem. I don't know what the line does. Presumably load Rails 5.0 defaults. Why after going to the trouble of upgrading?

To get to this I tried to upgrade several times. At first going a bit too quickly and then slower and slower and following diffs and blogs on upgrading. What I finally did was go directly from 5.0 to 5.2, because going in two steps sent me in loops about bundler versions. And from reading blogs and seeing what happened in my earlier trials I was fairly certain not much changed for me in Rails 5.1.

I finally concluded that something happened in the rake app:update step. So I accepted all the defaults except I kept the old routes.rb. Then went through the diffs a file at a time and changed back to what I had in 5.0, relaunched server and went through the steps to trigger the RestoResidLine.create step.

I had tried several times over the last few months, but in the last few days went carefully through about three upgrade trials. Left to do is put back in what got left out of the rake app:update accepting of defaults. I think they are minor. No first I need to make sure can upload to heroku.

FWIW I wanted to get to 5.2 to get ActiveStorage.

Postgres create not working after updating to Rails 5.2

1 Answers1