Getting PG Error from specs

[aaudette]

I have the following method using upsert:
def job_code
@code = JobCode.new(params[:api])
selector = {:store_id => @code.store_id, :source_id => @code.source_id}
setter = { :name => @code.name, :created_at => Time.now, :updated_at => Time.now }
JobCode.upsert(selector, setter)
render_json(@code, :created)
end

And here is the spec that is giving me trouble:
describe 'job_code' do
context 'when it is a new job_code' do
Given(:params) { {:format => 'json', :api=>{ :store_id=> 1, :source_id=>25, :name=>'Server'}} }
Then { lambda{ post :job_code, params }.should change(JobCode, :count) }
end

context 'when the item already exists' do
  Given!(:code) { FactoryGirl.create :job_code }
  Given(:params) {  {:format => 'json', :api=>{ :store_id=> code.store_id, :source_id=>code.source_id, :name=>code.name}} }
  Then { lambda{ post :job_code, params }.should_not change(JobCode, :count) }   
end

end

I can run each of these specs individually and everything works well, but when I run them together, I get the following error:

1. ApiController job_code when the item already exists
   Failure/Error: Then { lambda{ post :job_code, params }.should_not change(JobCode, :count) }
   PG::Error:
   ERROR: current transaction is aborted, commands ignored until end of transaction block

I can call this method with a script many times back-to back, and it works well. I'm also using upsert elsewhere without an issue. Also, all rows are successfully loaded in the database in all cases except for the test. Not sure if this is an Upsert issue or user error, but any insight is much appreciated!

[seamusabshere]

Would you try to get me a transcript of the SQL that's executed?

This might do it:

Upsert.logger.level = Logger::DEBUG

Not pretty, but it should work

[aaudette]

Thanks for the quick response!

Processing by ApiController#job_code as JSON
Parameters: {"api"=>{"store_id"=>1, "source_id"=>25, "name"=>"Server"}}
[upsert] SELECT a.attname AS name, format_type(a.atttypid, a.atttypmod) AS sql_type, d.adsrc AS default
FROM pg_attribute a LEFT JOIN pg_attrdef d
ON a.attrelid = d.adrelid AND a.attnum = d.adnum
WHERE a.attrelid = '"job_codes"'::regclass
AND a.attnum > 0 AND NOT a.attisdropped

[upsert] Creating or replacing database function "upsert2_0_1_job_codes_SEL_source_id_A_store_id_SET_cr3198577771" on table "job_codes" for selector "source_id", "store_id" and setter "created_at", "name", "source_id", "store_id", "updated_at"
[upsert]
CREATE OR REPLACE FUNCTION upsert2_0_1_job_codes_SEL_source_id_A_store_id_SET_cr3198577771("source_id_sel" integer, "store_id_sel" integer, "created_at_set" character varying(255), "name_set" character varying(255), "source_id_set" integer, "store_id_set" integer, "updated_at_set" character varying(255)) RETURNS VOID AS
$$
DECLARE
first_try INTEGER := 1;
BEGIN
LOOP
-- first try to update the key
UPDATE "job_codes" SET "name" = "name_set", "source_id" = "source_id_set", "store_id" = "store_id_set", "updated_at" = CAST("updated_at_set" AS timestamp without time zone)
WHERE "source_id" = "source_id_sel" AND "store_id" = "store_id_sel";
IF found THEN

            RETURN;
          END IF;
          -- not there, so try to insert the key
          -- if someone else inserts the same key concurrently,
          -- we could get a unique-key failure
          BEGIN
            INSERT INTO "job_codes"("created_at", "name", "source_id", "store_id", "updated_at") VALUES (CAST("created_at_set" AS timestamp without time zone), "name_set", "source_id_set", "store_id_set", CAST("updated_at_set" AS timestamp without time zone));

            RETURN;
          EXCEPTION WHEN unique_violation THEN
            -- seamusabshere 9/20/12 only retry once
            IF (first_try = 1) THEN
              first_try := 0;
            ELSE
              RETURN;
            END IF;
            -- Do nothing, and loop to try the UPDATE again.
          END;
        END LOOP;
      END;
      $$
      LANGUAGE plpgsql;

[upsert] SELECT upsert2_0_1_job_codes_SEL_source_id_A_store_id_SET_cr3198577771($1, $2, $3, $4, $5, $6, $7) with [25, 1, "2013-09-30 17:44:58.912634+00:00", "Server", 25, 1, "2013-09-30 17:44:58.912637+00:00"]
Completed 201 Created in 73ms (Views: 0.2ms | ActiveRecord: 0.0ms)
�[1m�[35m (0.3ms)�[0m SELECT COUNT() FROM "job_codes"
�[1m�[36m (0.2ms)�[0m �[1mROLLBACK�[0m
�[1m�[35m (0.1ms)�[0m BEGIN
�[1m�[36m (0.1ms)�[0m �[1mSAVEPOINT active_record_1�[0m
�[1m�[35mSQL (0.4ms)�[0m INSERT INTO "stores" ("created_at", "id", "name", "region_id", "store_number", "timezone", "updated_at") VALUES ($1, $2, $3, $4, $5, $6, $7) RETURNING "id" [["created_at", Mon, 30 Sep 2013 17:44:58 UTC +00:00], ["id", 42], ["name", "Test store"], ["region_id", nil], ["store_number", nil], ["timezone", "Eastern Time (US & Canada)"], ["updated_at", Mon, 30 Sep 2013 17:44:58 UTC +00:00]]
�[1m�[36m (0.1ms)�[0m �[1mRELEASE SAVEPOINT active_record_1�[0m
�[1m�[35m (0.1ms)�[0m SAVEPOINT active_record_1
�[1m�[36mSQL (0.6ms)�[0m �[1mINSERT INTO "job_codes" ("created_at", "name", "source_id", "store_id", "updated_at") VALUES ($1, $2, $3, $4, $5) RETURNING "id"�[0m [["created_at", Mon, 30 Sep 2013 17:44:58 UTC +00:00], ["name", "Server"], ["source_id", 25], ["store_id", 42], ["updated_at", Mon, 30 Sep 2013 17:44:58 UTC +00:00]]
�[1m�[35m (0.1ms)�[0m RELEASE SAVEPOINT active_record_1
�[1m�[36m (0.2ms)�[0m �[1mSELECT COUNT() FROM "job_codes" �[0m
Processing by ApiController#job_code as JSON
Parameters: {"api"=>{"store_id"=>42, "source_id"=>25, "name"=>"Server"}}
[upsert] SELECT upsert2_0_1_job_codes_SEL_source_id_A_store_id_SET_cr3198577771($1, $2, $3, $4, $5, $6, $7) with [25, 42, "2013-09-30 17:44:58.935755+00:00", "Server", 25, 42, "2013-09-30 17:44:58.935757+00:00"]
[upsert] Function "upsert2_0_1_job_codes_SEL_source_id_A_store_id_SET_cr3198577771" went missing, trying to recreate
[upsert] Creating or replacing database function "upsert2_0_1_job_codes_SEL_source_id_A_store_id_SET_cr3198577771" on table "job_codes" for selector "source_id", "store_id" and setter "created_at", "name", "source_id", "store_id", "updated_at"
[upsert]
CREATE OR REPLACE FUNCTION upsert2_0_1_job_codes_SEL_source_id_A_store_id_SET_cr3198577771("source_id_sel" integer, "store_id_sel" integer, "created_at_set" character varying(255), "name_set" character varying(255), "source_id_set" integer, "store_id_set" integer, "updated_at_set" character varying(255)) RETURNS VOID AS
$$
DECLARE
first_try INTEGER := 1;
BEGIN
LOOP
-- first try to update the key
UPDATE "job_codes" SET "name" = "name_set", "source_id" = "source_id_set", "store_id" = "store_id_set", "updated_at" = CAST("updated_at_set" AS timestamp without time zone)
WHERE "source_id" = "source_id_sel" AND "store_id" = "store_id_sel";
IF found THEN

            RETURN;
          END IF;
          -- not there, so try to insert the key
          -- if someone else inserts the same key concurrently,
          -- we could get a unique-key failure
          BEGIN
            INSERT INTO "job_codes"("created_at", "name", "source_id", "store_id", "updated_at") VALUES (CAST("created_at_set" AS timestamp without time zone), "name_set", "source_id_set", "store_id_set", CAST("updated_at_set" AS timestamp without time zone));

            RETURN;
          EXCEPTION WHEN unique_violation THEN
            -- seamusabshere 9/20/12 only retry once
            IF (first_try = 1) THEN
              first_try := 0;
            ELSE
              RETURN;
            END IF;
            -- Do nothing, and loop to try the UPDATE again.
          END;
        END LOOP;
      END;
      $$
      LANGUAGE plpgsql;

Completed 500 Internal Server Error in 2ms
�[1m�[35m (0.1ms)�[0m ROLLBACK

[friesencr]

we are running into the same thing. let me know if there is something to test. i am trying to dig into it.

[seamusabshere]

is the CREATE FUNCTION being run inside of a transaction that is then rolled back?

maybe try running some throwaway upserts before tests are run - that way the functions will already exist?

[friesencr]

i don't know upserts relationship to active records connection but rspec will normally put transactions around tests and rollback to make tests faster

i will try some things next week

[friesencr]

got it to work.

normally this would be sufficient. you can do this globally in a describe

# config
config.use_transactional_fixtures = false

# in a describe block
self.use_transactional_fixtures = false

we are using database cleaner which hijacks those settings. this is how we are solving the problem.

    before :all do
      DatabaseCleaner.strategy = :truncation
      DatabaseCleaner.clean_with(:truncation)
    end
    after :all do
      DatabaseCleaner.strategy = :transaction
      DatabaseCleaner.clean_with(:truncation)
    end

[seamusabshere]

for now just mentioning this in readme f8e09e9

[evadne]

This might have been fixed with our earlier thread-safety patch.

[evadne]

I ran into a similar situation today and found the following quite useful

SELECT relation::regclass, * FROM pg_locks WHERE NOT granted;

The culprit was a lock held on one of the tables due to schema creation within a transaction.

I worked around that problem with the following structure.

RSpec.feature('IBIS Import', type: :feature) {
  self.use_transactional_fixtures = false
  before(:each) {
    Rake::Task['data:inbound:install:medium'].invoke
    ActiveRecord::Base.connection.begin_transaction
  }
  after(:each) {
    ActiveRecord::Base.connection.rollback_transaction
    Rake::Task['data:inbound:install:base'].invoke
  }
  …
}

[Ch4s3]

Is there another fix for this?