change classification fallback to update fails on postgres

[dustin]

Harry sent along the traceback and logs, and I had a look.

I think what's happening here is that the same change is classified by the same scheduler twice, as suggested as a possibility in

master/buildbot/schedulers/basic.py
148         # NOTE: this may double-call gotChange for changes that arrive just as
149         # the scheduler starts up.  In practice, this doesn't hurt anything.

It looks like postgres is aborting the transaction after the first failed query, which is annoying but known:

dustin=# begin;
BEGIN
dustin=# insert into foo values (1);
INSERT 0 1
dustin=# insert into foo values (1);
ERROR:  duplicate key value violates unique constraint "foo_d_key"
dustin=# update foo set d=2;
ERROR:  current transaction is aborted, commands ignored until end of transaction block
}}

I suspect that this can be fixed by ending the transaction and starting a new one.  But, we should be revealing this problem with some tests, first.

[dustin]

This *is* tested, and the tests pass on Postgres. From the logs:

Jun  2 15:15:54 knuth postgres[23450]: [76-1] LOG:  execute pg8000_statement_0/pg8000_portal_0: BEGIN TRANSACTION
Jun  2 15:15:54 knuth postgres[23450]: [77-1] LOG:  execute <unnamed>/pg8000_portal_44: INSERT INTO scheduler_changes (objectid, changeid, important) VALUES ($1, $2, $3)
Jun  2 15:15:54 knuth postgres[23450]: [77-2] DETAIL:  parameters: $1 = '24', $2 = '3', $3 = '0'
Jun  2 15:15:54 knuth postgres[23450]: [78-1] LOG:  execute pg8000_statement_1/pg8000_portal_1: COMMIT TRANSACTION
Jun  2 15:15:54 knuth postgres[23450]: [79-1] LOG:  execute pg8000_statement_2/pg8000_portal_2: ROLLBACK TRANSACTION
Jun  2 15:15:54 knuth postgres[23450]: [80-1] LOG:  execute pg8000_statement_0/pg8000_portal_0: BEGIN TRANSACTION
Jun  2 15:15:54 knuth postgres[23450]: [81-1] LOG:  execute <unnamed>/pg8000_portal_45: INSERT INTO scheduler_changes (objectid, changeid, important) VALUES ($1, $2, $3)
Jun  2 15:15:54 knuth postgres[23450]: [81-2] DETAIL:  parameters: $1 = '24', $2 = '3', $3 = '1'
Jun  2 15:15:54 knuth postgres[23450]: [82-1] ERROR:  duplicate key value violates unique constraint "scheduler_changes_unique"
Jun  2 15:15:54 knuth postgres[23450]: [82-2] STATEMENT:  INSERT INTO scheduler_changes (objectid, changeid, important) VALUES ($1, $2, $3)
Jun  2 15:15:54 knuth postgres[23450]: [83-1] LOG:  execute pg8000_statement_2/pg8000_portal_2: ROLLBACK TRANSACTION
Jun  2 15:15:54 knuth postgres[23450]: [84-1] LOG:  execute pg8000_statement_0/pg8000_portal_0: BEGIN TRANSACTION
Jun  2 15:15:54 knuth postgres[23450]: [85-1] LOG:  execute <unnamed>/pg8000_portal_46: UPDATE scheduler_changes SET important=$1 WHERE scheduler_changes.objectid = $2 AND scheduler_changes.changeid = $3
Jun  2 15:15:54 knuth postgres[23450]: [85-2] DETAIL:  parameters: $1 = '1', $2 = '24', $3 = '3'
Jun  2 15:15:54 knuth postgres[23450]: [86-1] LOG:  execute pg8000_statement_1/pg8000_portal_1: COMMIT TRANSACTION
Jun  2 15:15:54 knuth postgres[23450]: [87-1] LOG:  execute pg8000_statement_2/pg8000_portal_2: ROLLBACK TRANSACTION
Jun  2 15:15:54 knuth postgres[23450]: [88-1] LOG:  execute pg8000_statement_0/pg8000_portal_0: BEGIN TRANSACTION
Jun  2 15:15:54 knuth postgres[23450]: [89-1] LOG:  execute <unnamed>/pg8000_portal_47: SELECT scheduler_changes.objectid, scheduler_changes.changeid, scheduler_changes.important
Jun  2 15:15:54 knuth postgres[23450]: [89-2]   FROM scheduler_changes ORDER BY scheduler_changes.changeid
Jun  2 15:15:54 knuth postgres[23450]: [90-1] LOG:  execute pg8000_statement_2/pg8000_portal_2: ROLLBACK TRANSACTION
Jun  2 15:15:54 knuth postgres[23450]: [91-1] LOG:  execute pg8000_statement_0/pg8000_portal_0: BEGIN TRANSACTION

Possibilities:

• sqlalchemy version (but metabuildbot tests the supported versions)
• postgres version (I'm using 8.4)
• postgres driver (I'm using pg8000, as the logs show)

Harry, what versions are you using?