SQLAlchemy: factory boy populates wrong field types in trasaction

[citizen-stig]

For instance I have a following model:

#models.py
from flask_sqlalchemy import SQLAlchemy

db = SQLAlchemy()

class User(db.Model):
    __tablename__ = "users"
    id = db.Column(db.Integer, primary_key=True)
    first_name = db.Column(db.String(80), nullable=False)
    last_name = db.Column(db.String, nullable=False)
    email = db.Column(db.String)
    some_id = db.Column(db.Integer, nullable=True)

I have a following factory for that model

# factories.py
class UserFactory(SQLAlchemyModelFactory):

    class Meta:
        model = User
        sqlalchemy_session = db.session

    email = factory.Sequence(lambda n: u'user%d@example.com' % n)
    first_name = factory.Iterator(['John', 'Jack', 'Joseph', 'Jason', 'Jerry'])
    last_name = factory.Iterator(['Smith', 'Jones', 'Black', 'Brown',
                                  'Anderson'])

And a following test

# test.py
class BaseTestCase(unittest.TestCase):

    @classmethod
    def setUpClass(cls):
        cls.app = app
        cls._ctx = cls.app.test_request_context()
        cls._ctx.push()
        db.drop_all()
        db.create_all()

    @classmethod
    def tearDownClass(cls):
        db.session.remove()
        db.engine.dispose()
        db.drop_all()

    def setUp(self):
        self.client = self.app.test_client()
        self._ctx = self.app.test_request_context()
        self._ctx.push()
        db.session.begin(subtransactions=True)

    def tearDown(self):
        db.session.close()
        db.session.rollback()
        self._ctx.pop()


class ProblemsTestCase(BaseTestCase):

    def test_str_conversion(self):
        # user = User(first_name='John', last_name='Doe', email='test@example.com')
        # db.session.add(user)
        # db.session.commit()
        user = UserFactory()
        some_id = u'4242'
        user.some_id = some_id
        db.session.commit()
        again_user = User.query.get(user.id)
        self.assertEqual(again_user.some_id, int(some_id))

This test will fail with following error: AssertionError: u'4242' != 4242

But will work if native SQLAlchemy model is created.
My environment: python 2.7, factory_boy==2.6.0, SQLAlchemy==1.0.9, Flask-SQLAlchemy==2.1

[citizen-stig]

The possible root cause is used transaction, because if I change the BaseTestCase like that:

class BaseTestCase(unittest.TestCase):

    @classmethod
    def setUpClass(cls):
        cls.app = app
        cls._ctx = cls.app.test_request_context()
        cls._ctx.push()

    @classmethod
    def tearDownClass(cls):
        db.session.remove()
        db.engine.dispose()

    def setUp(self):
        self.client = self.app.test_client()
        self._ctx = self.app.test_request_context()
        self._ctx.push()
        db.session.close()
        db.drop_all()
        db.create_all()

    def tearDown(self):
        db.session.close()
        self._ctx.pop()

Test will pass. But this approach is a much more slower.

[jeffwidman]

I am hitting something similar, I think it's either caused by Factory Boy binding to a different SQLAlchemy session/transaction than the one the test is in.

Possibly Factory boy is actually in the same session, but flushes or commits the session under the covers which makes it impossible to roll it back.

I'm still digging into it, but curious if you found anything more here...

[rbarrois]

This might indeed be caused by the default "do-not-flush" behavior of factory_boy.

The optional force-flush added in #262 could help you, would you mind trying with the current master?

[jeffwidman]

My underlying issue turned out to be something unrelated to FactoryBoy.

@citizen-stig I was able to track down the underlying issue by setting SQLALCHEMY_ECHO=True in my Flask app config and slowly stepping through the code in pdb while simultaneously watching the DB commands--that made it obvious where the problem was. Might find a similar process helpful for you to confirm where in the code this is happening.

[citizen-stig]

@rbarrois I've tried with current master and force_flush = True in Meta, but result is the same. Here is output with enabled echo for SQLAlchemy:

======================================================================
FAIL: test_str_conversion (tests.ProblemsTestCase)
----------------------------------------------------------------------
Traceback (most recent call last):
  File "/home/vagrant/factory_boy_253/tests.py", line 54, in test_str_conversion
    self.assertEqual(again_user.some_id, int(some_id))
nose.proxy.AssertionError: '4242' != 4242
-------------------- >> begin captured logging << --------------------
sqlalchemy.engine.base.Engine: INFO: select version()
sqlalchemy.engine.base.Engine: INFO: {}
sqlalchemy.engine.base.Engine: INFO: select current_schema()
sqlalchemy.engine.base.Engine: INFO: {}
sqlalchemy.engine.base.Engine: INFO: SELECT CAST('test plain returns' AS VARCHAR(60)) AS anon_1
sqlalchemy.engine.base.Engine: INFO: {}
sqlalchemy.engine.base.Engine: INFO: SELECT CAST('test unicode returns' AS VARCHAR(60)) AS anon_1
sqlalchemy.engine.base.Engine: INFO: {}
sqlalchemy.engine.base.Engine: INFO: show standard_conforming_strings
sqlalchemy.engine.base.Engine: INFO: {}
sqlalchemy.engine.base.Engine: INFO: select relname from pg_class c join pg_namespace n on n.oid=c.relnamespace where n.nspname=%(schema)s and relname=%(name)s
sqlalchemy.engine.base.Engine: INFO: {'schema': 'public', 'name': 'users'}
sqlalchemy.engine.base.Engine: INFO: select relname from pg_class c join pg_namespace n on n.oid=c.relnamespace where n.nspname=%(schema)s and relname=%(name)s
sqlalchemy.engine.base.Engine: INFO: {'schema': 'public', 'name': 'users'}
sqlalchemy.engine.base.Engine: INFO: 
CREATE TABLE public.users (
    id SERIAL NOT NULL, 
    first_name VARCHAR(80) NOT NULL, 
    last_name VARCHAR NOT NULL, 
    email VARCHAR, 
    some_id INTEGER, 
    PRIMARY KEY (id)
)


sqlalchemy.engine.base.Engine: INFO: {}
sqlalchemy.engine.base.Engine: INFO: COMMIT
factory.generate: DEBUG: BaseFactory: Preparing factories.UserFactory(extra={})
factory.generate: DEBUG: <class 'factories.UserFactory'>: Setting up next sequence (0)
factory.containers: DEBUG: LazyStub: Computing values for factories.UserFactory(first_name=<OrderedDeclarationWrapper for <factory.declarations.Iterator object at 0x7fb4033195c0>>, last_name=<OrderedDeclarationWrapper for <factory.declarations.Iterator object at 0x7fb4033195f8>>, email=<OrderedDeclarationWrapper for <factory.declarations.Sequence object at 0x7fb4032df7b8>>)
factory.generate: DEBUG: Iterator: Fetching next value from <factory.utils.ResetableIterator object at 0x7fb3fe9c80f0>
factory.generate: DEBUG: Iterator: Fetching next value from <factory.utils.ResetableIterator object at 0x7fb3fe9c8198>
factory.generate: DEBUG: Sequence: Computing next value of <function UserFactory.<lambda> at 0x7fb403315d90> for seq=0
factory.containers: DEBUG: LazyStub: Computed values, got factories.UserFactory(first_name='John', last_name='Smith', email='user0@example.com')
factory.generate: DEBUG: BaseFactory: Generating factories.UserFactory(first_name='John', last_name='Smith', email='user0@example.com')
sqlalchemy.engine.base.Engine: INFO: BEGIN (implicit)
sqlalchemy.engine.base.Engine: INFO: INSERT INTO public.users (first_name, last_name, email, some_id) VALUES (%(first_name)s, %(last_name)s, %(email)s, %(some_id)s) RETURNING public.users.id
sqlalchemy.engine.base.Engine: INFO: {'first_name': 'John', 'some_id': None, 'last_name': 'Smith', 'email': 'user0@example.com'}
sqlalchemy.engine.base.Engine: INFO: UPDATE public.users SET some_id=%(some_id)s WHERE public.users.id = %(public_users_id)s
sqlalchemy.engine.base.Engine: INFO: {'some_id': '4242', 'public_users_id': 1}
sqlalchemy.engine.base.Engine: INFO: ROLLBACK
--------------------- >> end captured logging << ---------------------

[citizen-stig]

I've created a git repository for that, so you can check it on your own.
Just run nose -w .

[jeffwidman]

@citizen-stig Link to the git repo?

[citizen-stig]

Oh, sorry, https://github.com/citizen-stig/factory_boy_253

[jeffwidman]

Looking at this now.
I haven't used nose much, but looks like the command is nosetests rather than nose.
The first test run threw an error because your test app uses factory_boy features that require a newer version of factory_boy than spec'd in your requirements.txt.

Second attempt threw an error because I didn't have Postgres setup... best practice when creating standalone reproductions of errors is to use an in-memory SQLite database. It's the polite thing to do so that it's easier for us maintainers to spend time fixing bugs instead of configuring databases.

Rather than taking the time to do this, I looked a bit deeper at your code. I think I understand the issue here--see my comments alongside your code:

def test_str_conversion(self):
        user = UserFactory()
        some_id = u'4242' 
        user.some_id = some_id  
        # you just assigned a string to be the value of a sqlalchemy integer column

        db.session.commit()
        # this is where I'd expect an exception to be raised by either SQLAlchemy or 
        # your underlying database driver. Instead, looking at the DB queries in your log,
        # it looks like the string is silently coerced to an int by SQLAlchemy right before
        # being sent to the DB.
        # commit() ends the DB transaction, but not the SQLAlchemy session
        # at this stage, you still have the user object in the sqlalchemy session identity map
        # user.some_id in the session is still a string. 
        # However, `SELECT some_id FROM user` will return an integer because that's what
        # got sent to the DB

        again_user = User.query.get(user.id)  
        # the `get` method is a special query that first attempts to find the object in the
        # session's identity map. Since you haven't closed the SQLAlchemy session, and
        # the object is still in the identity map from earlier, this query never hits the DB.
        # You can confirm this because there's no SELECT statement in your log after the
        # UPDATE. user.some_id remains a string in the SQLAlchemy session's identity map.
        # so now you're comparing a string value to an int. No surprise, it fails. 
        self.assertEqual(again_user.some_id, int(some_id))

Possibly this is a bug with SQLAlchemy. More likely it's intended behavior to support duck-typing alongside strict DB column typing.

Closing, as this isn't an issue with FactoryBoy.