tests are failing when using PostgreSQL database backend

[rutsky]

When running Buildbot test suite with BUILDBOT_TEST_DB_URL pointing to PostgreSQL 9.5 instance following errors occurs:

...
sqlalchemy.exc.IntegrityError: (IntegrityError) duplicate key value violates unique constraint "buildslaves_name"
DETAIL:  Key (name)=(bs1) already exists.
 'INSERT INTO buildslaves (name, info) VALUES (%(name)s, %(info)s)' ({'info': '{}', 'name': 'bs1'}, {'info': '{}', 'name': 'bs1'})


buildbot.test.unit.test_db_migrate_versions_024_add_buildslaves_table.Migration.test_empty_migration
===============================================================================
...
sqlalchemy.exc.InternalError: (InternalError) cannot drop table builder_masters because other objects depend on it
DETAIL:  constraint configured_workers_buildermasterid_fkey on table configured_workers depends on table builder_masters
HINT:  Use DROP ... CASCADE to drop the dependent objects too.
 '\nDROP TABLE builder_masters' {}

buildbot.test.integration.test_upgrade.TestWeirdChanges.testUpgradeChangeNoRevision
===============================================================================
...
exceptions.TypeError: can't escape unicode to binary

buildbot.test.unit.test_db_logs.TestRealDB.test_addLogLines_big_chunk
===============================================================================
...

I used PostgreSQL in Docker, I documented it here: ​https://github.com/buildbot/buildbot/pull/1955

[rutsky]

log of running tests

[dustin]

To reproduce, I ran

docker run -P -e POSTGRES_USER=bbtest -e POSTGRES_PASSWORD=bbtest postgres:9.5

then looked up the port with 'docker port', set

export BUILDBOT_TEST_DB_URL=postgresql+pg8000://bbtest:bbtest@127.0.0.1:32769/bbtest

and then ran the test suite.

I got a different set of errors:

Traceback (most recent call last):
  File "/home/dustin/p/buildbot/sandbox/local/lib/python2.7/site-packages/twisted/python/threadpool.py", line 246, in inContext
    result = inContext.theWork()
  File "/home/dustin/p/buildbot/sandbox/local/lib/python2.7/site-packages/twisted/python/threadpool.py", line 262, in <lambda>
    inContext.theWork = lambda: context.call(ctx, func, *args, **kw)
  File "/home/dustin/p/buildbot/sandbox/local/lib/python2.7/site-packages/twisted/python/context.py", line 118, in callWithContext
    return self.currentContext().callWithContext(ctx, func, *args, **kw)
  File "/home/dustin/p/buildbot/sandbox/local/lib/python2.7/site-packages/twisted/python/context.py", line 81, in callWithContext
    return func(*args,**kw)
  File "/home/dustin/p/buildbot/master/buildbot/db/pool.py", line 192, in __thd
    rv = callable(arg, *args, **kwargs)
  File "/home/dustin/p/buildbot/master/buildbot/test/unit/test_db_migrate_versions_018_add_sourcestampset.py", line 156, in verify_thd
    ], with_constrained_columns=['sourcestampsetid'])
  File "/home/dustin/p/buildbot/master/buildbot/test/unit/test_db_migrate_versions_018_add_sourcestampset.py", line 137, in thd_assertForeignKeys
    self.assertEqual(fks, exp)
  File "/home/dustin/p/buildbot/sandbox/local/lib/python2.7/site-packages/twisted/trial/_synctest.py", line 437, in assertEqual
    super(_Assertions, self).assertEqual(first, second, msg)
  File "/usr/lib/python2.7/unittest/case.py", line 513, in assertEqual
    assertion_func(first, second, msg=msg)
  File "/usr/lib/python2.7/unittest/case.py", line 742, in assertListEqual
    self.assertSequenceEqual(list1, list2, msg, seq_type=list)
  File "/usr/lib/python2.7/unittest/case.py", line 724, in assertSequenceEqual
    self.fail(msg)
twisted.trial.unittest.FailTest: Lists differ: [{'referred_columns': [u'id'],... != [{'referred_table': 'sourcesta...

First differing element 0:
{'referred_columns': [u'id'], 'referred_table': u'sourcestampsets', 'constrained_columns': [u'sourcestampsetid'], 'options': {'onupdate': None, 'deferrable': None, 'ondelete': None, 'initially': None, 'match': None}}
{'referred_table': 'sourcestampsets', 'referred_columns': ['id'], 'constrained_columns': ['sourcestampsetid']}

- [{'constrained_columns': [u'sourcestampsetid'],
?                           -

+ [{'constrained_columns': ['sourcestampsetid'],
-   'options': {'deferrable': None,
-               'initially': None,
-               'match': None,
-               'ondelete': None,
-               'onupdate': None},
-   'referred_columns': [u'id'],
?                        -

+   'referred_columns': ['id'],
-   'referred_table': u'sourcestampsets'}]
?                     -

+   'referred_table': 'sourcestampsets'}]

buildbot.test.unit.test_db_migrate_versions_018_add_sourcestampset.Migration.test_1_buildsets
===============================================================================
[FAIL]
Traceback (most recent call last):
  File "/home/dustin/p/buildbot/sandbox/local/lib/python2.7/site-packages/twisted/python/threadpool.py", line 246, in inContext
    result = inContext.theWork()
  File "/home/dustin/p/buildbot/sandbox/local/lib/python2.7/site-packages/twisted/python/threadpool.py", line 262, in <lambda>
    inContext.theWork = lambda: context.call(ctx, func, *args, **kw)
  File "/home/dustin/p/buildbot/sandbox/local/lib/python2.7/site-packages/twisted/python/context.py", line 118, in callWithContext
    return self.currentContext().callWithContext(ctx, func, *args, **kw)
  File "/home/dustin/p/buildbot/sandbox/local/lib/python2.7/site-packages/twisted/python/context.py", line 81, in callWithContext
    return func(*args,**kw)
  File "/home/dustin/p/buildbot/master/buildbot/db/pool.py", line 192, in __thd
    rv = callable(arg, *args, **kwargs)
  File "/home/dustin/p/buildbot/master/buildbot/test/unit/test_db_migrate_versions_018_add_sourcestampset.py", line 182, in verify_thd
    ], with_constrained_columns=['sourcestampsetid'])
  File "/home/dustin/p/buildbot/master/buildbot/test/unit/test_db_migrate_versions_018_add_sourcestampset.py", line 137, in thd_assertForeignKeys
    self.assertEqual(fks, exp)
  File "/home/dustin/p/buildbot/sandbox/local/lib/python2.7/site-packages/twisted/trial/_synctest.py", line 437, in assertEqual
    super(_Assertions, self).assertEqual(first, second, msg)
  File "/usr/lib/python2.7/unittest/case.py", line 513, in assertEqual
    assertion_func(first, second, msg=msg)
  File "/usr/lib/python2.7/unittest/case.py", line 742, in assertListEqual
    self.assertSequenceEqual(list1, list2, msg, seq_type=list)
  File "/usr/lib/python2.7/unittest/case.py", line 724, in assertSequenceEqual
    self.fail(msg)
twisted.trial.unittest.FailTest: Lists differ: [{'referred_columns': [u'id'],... != [{'referred_table': 'sourcesta...

First differing element 0:
{'referred_columns': [u'id'], 'referred_table': u'sourcestampsets', 'constrained_columns': [u'sourcestampsetid'], 'options': {'onupdate': None, 'deferrable': None, 'ondelete': None, 'initially': None, 'match': None}}
{'referred_table': 'sourcestampsets', 'referred_columns': ['id'], 'constrained_columns': ['sourcestampsetid']}

- [{'constrained_columns': [u'sourcestampsetid'],
?                           -

+ [{'constrained_columns': ['sourcestampsetid'],
-   'options': {'deferrable': None,
-               'initially': None,
-               'match': None,
-               'ondelete': None,
-               'onupdate': None},
-   'referred_columns': [u'id'],
?                        -

+   'referred_columns': ['id'],
-   'referred_table': u'sourcestampsets'}]
?                     -

+   'referred_table': 'sourcestampsets'}]

buildbot.test.unit.test_db_migrate_versions_018_add_sourcestampset.Migration.test_2_sourcestamp
===============================================================================
[ERROR]
Traceback (most recent call last):
  File "/home/dustin/p/buildbot/sandbox/local/lib/python2.7/site-packages/twisted/python/threadpool.py", line 246, in inContext
    result = inContext.theWork()
  File "/home/dustin/p/buildbot/sandbox/local/lib/python2.7/site-packages/twisted/python/threadpool.py", line 262, in <lambda>
    inContext.theWork = lambda: context.call(ctx, func, *args, **kw)
  File "/home/dustin/p/buildbot/sandbox/local/lib/python2.7/site-packages/twisted/python/context.py", line 118, in callWithContext
    return self.currentContext().callWithContext(ctx, func, *args, **kw)
  File "/home/dustin/p/buildbot/sandbox/local/lib/python2.7/site-packages/twisted/python/context.py", line 81, in callWithContext
    return func(*args,**kw)
  File "/home/dustin/p/buildbot/master/buildbot/db/pool.py", line 192, in __thd
    rv = callable(arg, *args, **kwargs)
  File "/home/dustin/p/buildbot/master/buildbot/test/util/migration.py", line 82, in upgrade_thd
    schema.runchange(version, change, 1)
  File "/home/dustin/p/buildbot/sandbox/local/lib/python2.7/site-packages/migrate/versioning/schema.py", line 93, in runchange
    change.run(self.engine, step)
  File "/home/dustin/p/buildbot/sandbox/local/lib/python2.7/site-packages/migrate/versioning/script/py.py", line 148, in run
    script_func(engine)
  File "/home/dustin/p/buildbot/master/buildbot/db/migrate/versions/028_sourcestamps_refactor.py", line 333, in upgrade
    drop_old_schema_parts(migrate_engine)
  File "/home/dustin/p/buildbot/master/buildbot/db/migrate/versions/028_sourcestamps_refactor.py", line 308, in drop_old_schema_parts
    sa.Column('id', sa.Integer, primary_key=True),
  File "/home/dustin/p/buildbot/sandbox/local/lib/python2.7/site-packages/sqlalchemy/sql/schema.py", line 416, in __new__
    metadata._remove_table(name, schema)
  File "/home/dustin/p/buildbot/sandbox/local/lib/python2.7/site-packages/sqlalchemy/util/langhelpers.py", line 60, in __exit__
    compat.reraise(exc_type, exc_value, exc_tb)
  File "/home/dustin/p/buildbot/sandbox/local/lib/python2.7/site-packages/sqlalchemy/sql/schema.py", line 411, in __new__
    table._init(name, metadata, *args, **kw)
  File "/home/dustin/p/buildbot/sandbox/local/lib/python2.7/site-packages/sqlalchemy/sql/schema.py", line 488, in _init
    self._init_items(*args)
  File "/home/dustin/p/buildbot/sandbox/local/lib/python2.7/site-packages/sqlalchemy/sql/schema.py", line 72, in _init_items
    item._set_parent_with_dispatch(self)
  File "/home/dustin/p/buildbot/sandbox/local/lib/python2.7/site-packages/sqlalchemy/sql/base.py", line 433, in _set_parent_with_dispatch
    self._set_parent(parent)
  File "/home/dustin/p/buildbot/sandbox/local/lib/python2.7/site-packages/sqlalchemy/sql/schema.py", line 1299, in _set_parent
    self._setup_on_memoized_fks(lambda fk: fk._set_remote_table(table))
  File "/home/dustin/p/buildbot/sandbox/local/lib/python2.7/site-packages/sqlalchemy/sql/schema.py", line 1310, in _setup_on_memoized_fks
    fn(fk)
  File "/home/dustin/p/buildbot/sandbox/local/lib/python2.7/site-packages/sqlalchemy/sql/schema.py", line 1299, in <lambda>
    self._setup_on_memoized_fks(lambda fk: fk._set_remote_table(table))
  File "/home/dustin/p/buildbot/sandbox/local/lib/python2.7/site-packages/sqlalchemy/sql/schema.py", line 1820, in _set_remote_table
    parenttable, tablekey, colname = self._resolve_col_tokens()
  File "/home/dustin/p/buildbot/sandbox/local/lib/python2.7/site-packages/sqlalchemy/sql/schema.py", line 1693, in _resolve_col_tokens
    "this ForeignKey's parent column is not yet associated "
sqlalchemy.exc.InvalidRequestError: this ForeignKey's parent column is not yet associated with a Table.

buildbot.test.unit.test_db_migrate_versions_028_sourcestamps_refactor.Migration.test_migration

[dustin]

Oh, that was different versions of pg8000 and sqlalchemy

[dustin]

Hm, it was just pg8000. With that fixed, I can't reproduce.

(v5.4.1) (sandbox)dustin@personal-devel ~/p/buildbot [master] $ pip list | grep -iE 'sqlal|pg8000'
pg8000 (1.9.14)
SQLAlchemy (0.7.10)
sqlalchemy-migrate (0.7.2)

ditto with

(v5.4.1) (sandbox)dustin@personal-devel ~/p/buildbot [master] $ pip list | grep -iE 'sqlal|pg8000'
pg8000 (1.9.14)
SQLAlchemy (1.0.11)
sqlalchemy-migrate (0.10.0)

@rutsky, help?

[dustin]

Hm, but running the whole suite makes buildbot.test.unit.test_db_migrate_versions_018_add_sourcestampset.Migration.test_1_buildsets and buildbot.test.unit.test_db_migrate_versions_018_add_sourcestampset.Migration.test_2_sourcestamps fail.

At least that's easy to fix..

​https://github.com/buildbot/buildbot/pull/1973

@rutsky, with that patch, how are things looking?

[rutsky]

I've got that errors with psycopg (instead of pg8000, btw, which is recommended?):

$ pip list | grep -iE 'sqlal|pg8000|pg'
psycopg2 (2.6.1)
SQLAlchemy (0.7.10)
sqlalchemy-migrate (0.7.2)

Let me check what changes your patch...

[rutsky]

My PostgreSQL is almost equivalent to yours:

pip install psycopg2
sudo docker run --name bb-test-postgres -e POSTGRES_PASSWORD=password \
       -p 127.0.0.1:15432:5432 -d postgres:9.5
BUILDBOT_TEST_DB_URL=postgresql://postgres:password@localhost:15432/postgres trial --reporter=text buildbot.test

only PostgreSQL driver differs.

Also I have system-wide libpq-dev version 9.3.10, but I don't think this matters.

Dustin, can you try Python's psycopg2 driver? (If it should be supported. If it is not, that should be documented.)

[rutsky]

tests output on PR 1973 with psycopg2 driver

[rutsky]

Error log with your PR is a bit shorter, than without your changes, so I think your changes fixing something on psycopg2 driver too :)

[dustin]

 $ export BUILDBOT_TEST_DB_URL=postgresql+psycopg2://bbtest:bbtest@127.0.0.1:32768/bbtest
 $ pip freeze | grep -iE 'sqlal|pg'
pg8000==1.9.14
psycopg2==2.6.1
SQLAlchemy==1.0.11
sqlalchemy-migrate==0.10.0
$ dpkg -l libpq-dev
Desired=Unknown/Install/Remove/Purge/Hold
| Status=Not/Inst/Conf-files/Unpacked/halF-conf/Half-inst/trig-aWait/Trig-pend
|/ Err?=(none)/Reinst-required (Status,Err: uppercase=bad)
||/ Name               Version        Architecture   Description
+++-==================-==============-==============-==========================================
ii  libpq-dev          9.3.11-0ubuntu amd64          header files for libpq5 (PostgreSQL librar
 $ trial buildbot.net
...
PASSED (skips=83, successes=4343)

other combinations I should try?

[dustin]

That was with postgres 9.5 run via docker; same result with 9.3.

[rutsky]

other combinations I should try?

I think no. At least issues that I reported originally all resolved now.

This issue is fixed, thanks!

Please close it as soon as you will done all work with it (if you have any).