Regression introduced by r16739 -- `ManyRelatedManager.add()` doesn't commit to database

[Daniel Swarbrick]

Models are as follows (simplified):

class OrgUnit(models.Model):
    name = models.CharField(max_length=64, unique=True)
    description = models.CharField(_('description'), max_length=128)

class UserProfile(models.Model):
    user = models.ForeignKey(User, unique=True)
    favourites = models.ManyToManyField(OrgUnit, blank=True)

Following code does not work as it used to (in a view):

fav_list = request.user.get_profile().favourites
orgunit = OrgUnit.objects.get(pk=13)
fav_list.add(orgunit)

Immediately after the fav_list.add(), fav_list appears to contain the orgunit (cached), but it is not committed to the database (Postgres).

Reverting to r16738 restores the correct behaviour.

[Ramiro Morales]

What trunk SVN revision are you using? Make you sure it's a very recent one because there were followup commits related to the feature added in such commit.

[Daniel Swarbrick]

Using latest trunk (r16819), current as of a moment ago.

Interestingly, fav_list.remove(orgunit) will work. It just seems buggy when trying to add objects.

[Alex Gaynor]

Marking as accepted because this sounds very plausible, however can you please try to come up with a unittest for Django's tests on this, I'm not quite bright enough to extract one from the description. Thanks for taking the time to test against trunk!

[Daniel Swarbrick]

I don't have time to write a unit test, but I can shed a little more light on the problem. After turning on Postgres query logging, it appears that bulk_create() does the INSERT, but never commits it. For example:

2011-09-18 20:22:29 CEST LOG:  statement: BEGIN
2011-09-18 20:22:29 CEST LOG:  statement: SELECT "provisioning_device_sip"."sip_id" FROM "provisioning_device_sip" WHERE ("provisioning_device_sip"."device_id" = 131  AND "provisioning_device_sip"."sip_id" IN (160, 214, 159))
2011-09-18 20:22:29 CEST LOG:  statement: INSERT INTO "provisioning_device_sip" ("device_id", "sip_id") VALUES (131, 160), (131, 214), (131, 159)
2011-09-18 20:22:29 CEST LOG:  statement: SHOW default_transaction_isolation
2011-09-18 20:22:29 CEST LOG:  statement: SET default_transaction_isolation TO 'read uncommitted'
2011-09-18 20:22:29 CEST LOG:  statement: BEGIN
2011-09-18 20:22:29 CEST LOG:  statement: SELECT "auth_user"."id", "auth_user"."username", "auth_user"."first_name", "auth_user"."last_name", "auth_user"."email", "auth_user"."password", "auth_user"."is_staff", "auth_user"."is_active", "auth_user"."is_superuser", "auth_user"."last_login", "auth_user"."date_joined" FROM "auth_user" WHERE "auth_user"."id" = 1 

The second SELECT is after a form.save() and HTTP redirect. Note that there is never an explicit commit of the bulk insert.

On a whim, I monkey-patched a "transaction.commit(using=self.db)" just before "return objs" in bulk_create() in query.py. Whilst possibly not optimal, the explicit commit fixed the problem.

[Daniel Swarbrick]

Make that a "transaction.commit_unless_managed(using=self.db)" :)

[Daniel Swarbrick]

<bump>

Am I seriously the only one seeing this so far?

[Julien Phalip]

Marking as blocker to be sure this potential regression doesn't fall through the cracks. Note that providing a failing testcase will greatly increase the speed of this getting fixed (that is, if a bug is actually evidenced).

[Daniel Swarbrick]

Can do, although I'm amazed nobody else has spotted this so far. Any m2m ModelForm will exhibit the bug - although only the very observant will notice something amiss, as it fails silently.

Will try to add a test case this afternoon.

EDIT: Correction - m2m ModelForms don't exhibit the bug, as I suspect they are internally calling the save() method on the parent object. However, manipulating a list of m2m children manually will exhibit the bug.

[Daniel Swarbrick]

I think I may have found the cause of this bug. When using a vanilla django checkout, without my explicit transaction commit mentioned above, the following will not work:

parent_obj.m2m_children.add(new_child_obj)

Inspecting parent_obj.m2m_children.all() shows the new_child_obj (cached), but if the cache is invalidated (eg. start new django shell, or new request) the new_child_obj is absent from parent_obj.m2m_children.all().

However, if the parent_obj is explicitly saved after adding the new_child_obj, eg.

parent_obj.m2m_children.add(new_child_obj)
parent_obj.save()

then the new_child_obj is committed to the DB, and is present in subsequent requests.

This is new behaviour - the explicit parent_obj.save() was not required before r16739. I'm not sure if this still qualifies as a bug, or whether it is in fact a fix for a long-standing, incorrect behaviour.

[Daniel Swarbrick]

Furthermore, an explicit parent_obj.save() is not required when doing

parent_obj.m2m_children.remove(child_obj)

The child_obj is removed from the m2m_children table immediately.

This smells to me kinda like inconsistent behaviour, that should either be remedied, or very clearly documented.

[Ramiro Morales]

#17112 was a duplicate and has some additional notes. Among them this one:

I'm not sure how to create an automated test for this, because the problem only exhibits when reading from the database from a different process or transaction.

[Preston Holmes]

regression test

[Karen Tracey]

I am confused by this test case:

class TestManyToManyAddTransaction(TransactionTestCase):
    def test_manyrelated_add_commit(self):
        """test for 16818"""
        a = M2mA.objects.create()
        b = M2mB.objects.create(fld=10)
        a.others.add(b)
        transaction.rollback()
        self.assertQuerysetEqual(a.others.all(),['<M2mB: M2mB object>'])

The test explicitly rolls back what it's done and then tries to check that what it did wasn't rolled back?

[anonymous]

The .add() issues a BEGIN but no COMMIT. The ROLLBACK will undo the uncommitted bulk insert, confirming the bug (missing COMMIT). When fixed, the bulk insert will already be committed and the ROLLBACK won't undo it. That's my understanding, anyway :) This type of test was suggested to ptone by Alex Gaynor on IRC.

[Tai Lee]

The comment above was from me. Forgot to log in.

[Karen Tracey]

Oh I see, it's assuming autocommit behavior should be in effect, which I guess it should since it's a TransactionTestCase and it's done nothing to change from the default autocommit behavior.

[Karen Tracey]

Tentative fix

[Karen Tracey]

Attached patch makes the test run successfully on the 3 backends I have available to test where it was failing before (sqlite3, MySQL/InnoDB, PostgreSQL). Possibly it would be a good idea to factor out that force-managed stuff into a reusable bit that could be shared by different operations that require it...in a brief scan I see it in the insert (where I stole it from) and now bulk_insert and django/db/models/deletion.py has something very similar. But first I'd like some confirmation from someone with more ORM knowledge than me that that's the right thing to do to correct the error here.

[Adrian Holovaty]

In [17189]:

Fixed #16818 -- Fixed ORM bug with many-to-many add() method where it wasn't committing the change. Thanks, pressureman and kmtracey