FieldTracker infinite recursion on deleting object #533

brianmay · 2022-09-13T22:52:36Z

Problem

Call obj.delete() results in:

Fatal Python error: _Py_CheckRecursiveCall: Cannot recover from stack overflow.
Python runtime state: initialized

Current thread 0x00007f955a596280 (most recent call first):
  File "/home/brian/.asdf/installs/python/3.9.7/lib/python3.9/abc.py", line 119 in __instancecheck__
  File "/home/brian/.cache/pypoetry/virtualenvs/karaage-uhi1oUwy-py3.9/lib/python3.9/site-packages/django/db/models/sql/query.py", line 1443 in build_filter
  File "/home/brian/.cache/pypoetry/virtualenvs/karaage-uhi1oUwy-py3.9/lib/python3.9/site-packages/django/db/models/sql/query.py", line 1562 in _add_q
  File "/home/brian/.cache/pypoetry/virtualenvs/karaage-uhi1oUwy-py3.9/lib/python3.9/site-packages/django/db/models/sql/query.py", line 1532 in add_q
  File "/home/brian/.cache/pypoetry/virtualenvs/karaage-uhi1oUwy-py3.9/lib/python3.9/site-packages/django/db/models/query.py", line 1445 in _filter_or_exclude_inplace
  File "/home/brian/.cache/pypoetry/virtualenvs/karaage-uhi1oUwy-py3.9/lib/python3.9/site-packages/django/db/models/query.py", line 1438 in _filter_or_exclude
  File "/home/brian/.cache/pypoetry/virtualenvs/karaage-uhi1oUwy-py3.9/lib/python3.9/site-packages/django/db/models/query.py", line 1420 in filter
  File "/home/brian/.cache/pypoetry/virtualenvs/karaage-uhi1oUwy-py3.9/lib/python3.9/site-packages/django/db/models/manager.py", line 85 in manager_method
  File "/home/brian/.cache/pypoetry/virtualenvs/karaage-uhi1oUwy-py3.9/lib/python3.9/site-packages/django/db/models/base.py", line 724 in refresh_from_db
  File "/home/brian/.cache/pypoetry/virtualenvs/karaage-uhi1oUwy-py3.9/lib/python3.9/site-packages/model_utils/tracker.py", line 375 in inner
  File "/home/brian/.cache/pypoetry/virtualenvs/karaage-uhi1oUwy-py3.9/lib/python3.9/site-packages/django/db/models/query_utils.py", line 178 in __get__
  File "/home/brian/.cache/pypoetry/virtualenvs/karaage-uhi1oUwy-py3.9/lib/python3.9/site-packages/model_utils/tracker.py", line 75 in __get__
  File "/home/brian/.cache/pypoetry/virtualenvs/karaage-uhi1oUwy-py3.9/lib/python3.9/site-packages/model_utils/tracker.py", line 208 in get_field_value
  File "/home/brian/.cache/pypoetry/virtualenvs/karaage-uhi1oUwy-py3.9/lib/python3.9/site-packages/model_utils/tracker.py", line 234 in <dictcomp>
  File "/home/brian/.cache/pypoetry/virtualenvs/karaage-uhi1oUwy-py3.9/lib/python3.9/site-packages/model_utils/tracker.py", line 234 in current
  File "/home/brian/.cache/pypoetry/virtualenvs/karaage-uhi1oUwy-py3.9/lib/python3.9/site-packages/model_utils/tracker.py", line 216 in set_saved_fields
  File "/home/brian/.cache/pypoetry/virtualenvs/karaage-uhi1oUwy-py3.9/lib/python3.9/site-packages/model_utils/tracker.py", line 184 in __exit__
  File "/home/brian/.cache/pypoetry/virtualenvs/karaage-uhi1oUwy-py3.9/lib/python3.9/site-packages/model_utils/tracker.py", line 375 in inner
  File "/home/brian/.cache/pypoetry/virtualenvs/karaage-uhi1oUwy-py3.9/lib/python3.9/site-packages/django/db/models/query_utils.py", line 178 in __get__
  File "/home/brian/.cache/pypoetry/virtualenvs/karaage-uhi1oUwy-py3.9/lib/python3.9/site-packages/model_utils/tracker.py", line 75 in __get__
  File "/home/brian/.cache/pypoetry/virtualenvs/karaage-uhi1oUwy-py3.9/lib/python3.9/site-packages/model_utils/tracker.py", line 208 in get_field_value
  File "/home/brian/.cache/pypoetry/virtualenvs/karaage-uhi1oUwy-py3.9/lib/python3.9/site-packages/model_utils/tracker.py", line 234 in <dictcomp>
  File "/home/brian/.cache/pypoetry/virtualenvs/karaage-uhi1oUwy-py3.9/lib/python3.9/site-packages/model_utils/tracker.py", line 234 in current
  File "/home/brian/.cache/pypoetry/virtualenvs/karaage-uhi1oUwy-py3.9/lib/python3.9/site-packages/model_utils/tracker.py", line 216 in set_saved_fields
  File "/home/brian/.cache/pypoetry/virtualenvs/karaage-uhi1oUwy-py3.9/lib/python3.9/site-packages/model_utils/tracker.py", line 184 in __exit__
  File "/home/brian/.cache/pypoetry/virtualenvs/karaage-uhi1oUwy-py3.9/lib/python3.9/site-packages/model_utils/tracker.py", line 375 in inner
  [...]

Environment

Django Model Utils version: 4.2.0
Django version: 4.1.1
Python version: 3.9.7

The text was updated successfully, but these errors were encountered:

brianmay · 2022-09-13T23:32:11Z

Hmm. Problem is related object has a foreign key to this object with on_delete=models.SET_NULL, so we need to set this value to None.

This happens in django/db/models/deletion.py line 505:

setattr(obj, field.attname, value)

Where obj points to instance of related object, field.attname is the name of the field, and value is None.

If I change the on_delete to models.CASCADE then it works.

If I change the on_delete to models.PROTECT then it fails, but earlier.

Will try to create a simple test case. Later.

brianmay · 2022-09-13T23:59:51Z

More information.

The __set__ method in tracker calls the __get__ method. This is what crashes. Bit puzzled why the stack trace does not include this.

The __set__ method has code to protect against infinite recursion. But this does not help, because the infinite recursion occurs in the __get__ method (see stack trace) not the __set__ method.

brianmay · 2022-09-14T00:12:00Z

Here is a better stack trace (I stopped after second call to __get__):.

-> institute.delete()
  /home/brian/tree/unimelb/karaage/karaage/karaage/institutes/models.py(102)delete()
-> super(Institute, self).delete(*args, **kwargs)
  /home/brian/.cache/pypoetry/virtualenvs/karaage-uhi1oUwy-py3.9/lib/python3.9/site-packages/django/db/models/base.py(1137)delete()
-> return collector.delete()
  /home/brian/.cache/pypoetry/virtualenvs/karaage-uhi1oUwy-py3.9/lib/python3.9/site-packages/django/db/models/deletion.py(505)delete()
-> setattr(obj, field.attname, value)
  /home/brian/.cache/pypoetry/virtualenvs/karaage-uhi1oUwy-py3.9/lib/python3.9/site-packages/model_utils/tracker.py(98)__set__()
-> getattr(instance, self.field_name)
  /home/brian/.cache/pypoetry/virtualenvs/karaage-uhi1oUwy-py3.9/lib/python3.9/site-packages/model_utils/tracker.py(75)__get__()
-> value = self.descriptor.__get__(instance, owner)
  /home/brian/.cache/pypoetry/virtualenvs/karaage-uhi1oUwy-py3.9/lib/python3.9/site-packages/django/db/models/query_utils.py(178)__get__()
-> instance.refresh_from_db(fields=[field_name])
  /home/brian/.cache/pypoetry/virtualenvs/karaage-uhi1oUwy-py3.9/lib/python3.9/site-packages/model_utils/tracker.py(376)inner()
-> return original(instance, *args, **kwargs)
  /home/brian/.cache/pypoetry/virtualenvs/karaage-uhi1oUwy-py3.9/lib/python3.9/site-packages/model_utils/tracker.py(184)__exit__()
-> self.tracker.set_saved_fields(fields=reset_fields)
  /home/brian/.cache/pypoetry/virtualenvs/karaage-uhi1oUwy-py3.9/lib/python3.9/site-packages/model_utils/tracker.py(216)set_saved_fields()
-> self.saved_data.update(**self.current(fields=fields))
  /home/brian/.cache/pypoetry/virtualenvs/karaage-uhi1oUwy-py3.9/lib/python3.9/site-packages/model_utils/tracker.py(234)current()
-> return {f: self.get_field_value(f) for f in fields}
  /home/brian/.cache/pypoetry/virtualenvs/karaage-uhi1oUwy-py3.9/lib/python3.9/site-packages/model_utils/tracker.py(234)<dictcomp>()
-> return {f: self.get_field_value(f) for f in fields}
  /home/brian/.cache/pypoetry/virtualenvs/karaage-uhi1oUwy-py3.9/lib/python3.9/site-packages/model_utils/tracker.py(208)get_field_value()
-> return getattr(self.instance, self.field_map[field])
> /home/brian/.cache/pypoetry/virtualenvs/karaage-uhi1oUwy-py3.9/lib/python3.9/site-packages/model_utils/tracker.py(70)__get__()
-> def __get__(self, instance, owner):

brianmay · 2022-09-15T22:28:04Z

We delete a database record.
This needs to set a field to NULL on a related object.
This calls the __set__ method, which is intercepted by tracker.
Tracker needs to know what the original value was. So it calls the __get__ method to get the original value.
This calls code inside Django, which eventually calls refresh_from_db to actually retrieve the values.
refresh_from_db is intercepted by tracker. We want to make sure when loading from the database, we save the values we retrieved as the original values. We load the values. And then call current in order retrieve the values, so we can save them.
Eventually we call __get__, which results in infinite recursion.

The reasoning behind each individual step makes sense, and is correct. But when you combine all these correct steps together, you get code that is obviously broken.

brianmay · 2022-09-19T23:15:59Z

Trying this library instead: https://pypi.org/project/django-tracking-model/

chapimenge3 · 2022-10-02T18:37:05Z

@brianmay could you please write the step to reproduce the bug in detail ?

thank you.

brianmay · 2022-10-03T21:22:01Z

Will add creating a simple test case this to my to do list. But not a lot of time lately.

In the meantime this is the full code that caused the problem:

https://github.com/Karaage-Cluster/karaage/tree/field_tracking_broken

This is the field_tracking_broken branch.

$ poetry run python -m tldap.test.slapd pytest -x karaage/tests/institutes/test_models.py -k test_change_group -s
Starting slapd...
DEBUG:slapd:creating temp directory /tmp/brian/tmph2m7q1u3/ldif-data
DEBUG:Slapd:writing config to /tmp/brian/tmph2m7q1u3/slapd.conf
_#################### 100.00% eta   none elapsed            none fast!
Closing DB...
DEBUG:Slapd:testing configuration
config file testing succeeded
DEBUG:Slapd:configuration seems ok
INFO:Slapd:starting slapd
INFO:slapd:Found available port 55641
DEBUG:Slapd:Connecting to ('127.0.0.1', 55641)
DEBUG:Slapd:Connecting to ('127.0.0.1', 55641)
DEBUG:Slapd:slapd ready at ldap://127.0.0.1:55641/
Contents of LDAP server follow:

DEBUG:Slapd:ldapsearch filter='(objectClass=*)'
dn: dc=python-ldap,dc=org
dc: python-ldap
o: python-ldap
objectClass: dcObject
objectClass: organization

dn: cn=Manager,dc=python-ldap,dc=org
cn: Manager
objectClass: simpleSecurityObject
objectClass: organizationalRole

dn: cn=default,dc=python-ldap,dc=org
objectClass: top
objectClass: device
objectClass: pwdPolicy
pwdAttribute: userPassword
pwdLockout: TRUE
cn: default

dn: ou=People,dc=python-ldap,dc=org
objectClass: top
objectClass: OrganizationalUnit
ou: People

dn: ou=Groups,dc=python-ldap,dc=org
objectClass: top
objectClass: OrganizationalUnit
ou: Groups

Running command ['pytest', '-x', 'karaage/tests/institutes/test_models.py', '-k', 'test_change_group', '-s']...
===================================================================== test session starts =====================================================================
platform linux -- Python 3.9.7, pytest-7.1.3, pluggy-1.0.0
django: settings: karaage.tests.settings (from ini)
rootdir: /home/brian/tree/unimelb/karaage/karaage, configfile: pytest.ini
plugins: django-4.5.2, cov-3.0.0, Faker-14.2.0
collected 4 items / 3 deselected / 1 selected

karaage/tests/institutes/test_models.py Fatal Python error: _Py_CheckRecursiveCall: Cannot recover from stack overflow.
Python runtime state: initialized

Current thread 0x00007f0160a26280 (most recent call first):
  File "/home/brian/.asdf/installs/python/3.9.7/lib/python3.9/abc.py", line 119 in __instancecheck__
[...]

Note:

This requires a copy of slapd. No configuration required, just need access to the binary. The tests will configure an instance on the fly.
The stack trace produced, while correct, is missing entries that are clearly shown if I stop code execution in the debugger and show the stack trace.

brianmay · 2022-10-03T21:35:55Z

Actually never mind, slapd not required, this is simpler:

Will leave the previous version with slapd just in case it helps.

$ poetry install
[...]
$ poetry run pytest -x karaage/tests/institutes/test_models.py -k test_change_group -s
===================================================================== test session starts =====================================================================
platform linux -- Python 3.9.7, pytest-7.1.3, pluggy-1.0.0
django: settings: karaage.tests.settings (from ini)
rootdir: /home/brian/tree/unimelb/karaage/karaage, configfile: pytest.ini
plugins: django-4.5.2, cov-3.0.0, Faker-14.2.0
collected 4 items / 3 deselected / 1 selected

karaage/tests/institutes/test_models.py Fatal Python error: _Py_CheckRecursiveCall: Cannot recover from stack overflow.
Python runtime state: initialized

Current thread 0x00007f9ec497c280 (most recent call first):
  File "/home/brian/.asdf/installs/python/3.9.7/lib/python3.9/abc.py", line 119 in __instancecheck__
  File "/home/brian/.cache/pypoetry/virtualenvs/karaage-uhi1oUwy-py3.9/lib/python3.9/site-packages/django/db/models/sql/query.py", line 1443 in build_filter
[...]

hendrikschneider · 2023-01-11T16:10:32Z

any update here?

nick-prat · 2024-05-23T21:28:48Z

I believe I found a fix for this here: #620

nick-prat mentioned this issue May 23, 2024

Fixed an infinite recursion bug when deleting models related to a tracked model with a ForeignKey #620

Open

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

FieldTracker infinite recursion on deleting object #533

FieldTracker infinite recursion on deleting object #533

brianmay commented Sep 13, 2022

brianmay commented Sep 13, 2022

brianmay commented Sep 13, 2022

brianmay commented Sep 14, 2022

brianmay commented Sep 15, 2022

brianmay commented Sep 19, 2022

chapimenge3 commented Oct 2, 2022

brianmay commented Oct 3, 2022 •

edited

Loading

brianmay commented Oct 3, 2022 •

edited

Loading

hendrikschneider commented Jan 11, 2023

nick-prat commented May 23, 2024

FieldTracker infinite recursion on deleting object #533

FieldTracker infinite recursion on deleting object #533

Comments

brianmay commented Sep 13, 2022

Problem

Environment

brianmay commented Sep 13, 2022

brianmay commented Sep 13, 2022

brianmay commented Sep 14, 2022

brianmay commented Sep 15, 2022

brianmay commented Sep 19, 2022

chapimenge3 commented Oct 2, 2022

brianmay commented Oct 3, 2022 • edited Loading

brianmay commented Oct 3, 2022 • edited Loading

hendrikschneider commented Jan 11, 2023

nick-prat commented May 23, 2024

brianmay commented Oct 3, 2022 •

edited

Loading

brianmay commented Oct 3, 2022 •

edited

Loading