[Django] #30114: Strange ValidationError issue
Django
-------------------------------------+-------------------------------------
Reporter: Jerry | Owner: nobody
Vinokurov |
Type: Bug | Status: new
Component: Database | Version: 2.1
layer (models, ORM) | Keywords: validationerror,
Severity: Normal | uuid
Triage Stage: | Has patch: 0
Unreviewed |
Needs documentation: 0 | Needs tests: 0
Patch needs improvement: 0 | Easy pickings: 0
UI/UX: 0 |
-------------------------------------+-------------------------------------
Our project uses UUIDs as primary keys on a number of models. This works
as expected for the majority of the time, but at some point, we run into
the following error:
{{{
ValidationError: ["'f0c9eb37-a073-47b5-bbb1-589920939c5e' is not a valid
UUID."]
}}}
This is in fact a valid UUID and also a UUID in our system. We use Sentry
for our error reporting, which gives the entire stack trace:
{{{
ValidationError: ["'670e5eaf-d231-305e-bb5b-8c8fb0262574' is not a valid
UUID."]
File "django/core/handlers/exception.py", line 34, in inner
response = get_response(request)
File "django/core/handlers/base.py", line 126, in _get_response
response = self.process_exception_by_middleware(e, request)
File "django/core/handlers/base.py", line 124, in _get_response
response = wrapped_callback(request, *callback_args,
**callback_kwargs)
File "python3.6/contextlib.py", line 52, in inner
return func(*args, **kwds)
File "django/contrib/admin/options.py", line 604, in wrapper
return self.admin_site.admin_view(view)(*args, **kwargs)
File "django/utils/decorators.py", line 142, in _wrapped_view
response = view_func(request, *args, **kwargs)
File "django/views/decorators/cache.py", line 44, in _wrapped_view_func
response = view_func(request, *args, **kwargs)
File "django/contrib/admin/sites.py", line 223, in inner
return view(request, *args, **kwargs)
File "django/utils/decorators.py", line 45, in _wrapper
return bound_method(*args, **kwargs)
File "django/utils/decorators.py", line 142, in _wrapped_view
response = view_func(request, *args, **kwargs)
File "django/contrib/admin/options.py", line 1792, in changelist_view
'selection_note': _('0 of %(cnt)s selected') % {'cnt':
len(cl.result_list)},
File "django/db/models/query.py", line 250, in __len__
self._fetch_all()
File "django/db/models/query.py", line 1188, in _fetch_all
self._prefetch_related_objects()
File "django/db/models/query.py", line 723, in _prefetch_related_objects
prefetch_related_objects(self._result_cache,
*self._prefetch_related_lookups)
File "django/db/models/query.py", line 1569, in prefetch_related_objects
obj_list, additional_lookups = prefetch_one_level(obj_list,
prefetcher, lookup, level)
File "django/db/models/query.py", line 1682, in prefetch_one_level
prefetcher.get_prefetch_queryset(instances,
lookup.get_current_queryset(level)))
File "django/contrib/contenttypes/fields.py", line 194, in
get_prefetch_queryset
ret_val.extend(ct.get_all_objects_for_this_type(pk__in=fkeys))
File "django/db/models/query.py", line 268, in __iter__
self._fetch_all()
File "django/db/models/query.py", line 1186, in _fetch_all
self._result_cache = list(self._iterable_class(self))
File "django/db/models/query.py", line 54, in __iter__
results = compiler.execute_sql(chunked_fetch=self.chunked_fetch,
chunk_size=self.chunk_size)
File "django/db/models/sql/compiler.py", line 1052, in execute_sql
sql, params = self.as_sql()
File "django/db/models/sql/compiler.py", line 464, in as_sql
where, w_params = self.compile(self.where) if self.where is not None
else ("", [])
File "django/db/models/sql/compiler.py", line 390, in compile
sql, params = node.as_sql(self, self.connection)
File "django/db/models/sql/where.py", line 81, in as_sql
sql, params = compiler.compile(child)
File "django/db/models/sql/compiler.py", line 390, in compile
sql, params = node.as_sql(self, self.connection)
File "django/db/models/lookups.py", line 355, in as_sql
return super().as_sql(compiler, connection)
File "django/db/models/lookups.py", line 163, in as_sql
rhs_sql, rhs_params = self.process_rhs(compiler, connection)
File "django/db/models/lookups.py", line 339, in process_rhs
sqls, sqls_params = self.batch_process_rhs(compiler, connection, rhs)
File "django/db/models/lookups.py", line 231, in batch_process_rhs
pre_processed = super().batch_process_rhs(compiler, connection, rhs)
File "django/db/models/lookups.py", line 51, in batch_process_rhs
_, params = self.get_db_prep_lookup(rhs, connection)
File "django/db/models/lookups.py", line 186, in get_db_prep_lookup
if self.get_db_prep_lookup_value_is_iterable else
File "django/db/models/lookups.py", line 185, in <listcomp>
[get_db_prep_value(v, connection, prepared=True) for v in value]
File "django/db/models/fields/__init__.py", line 2316, in
get_db_prep_value
value = self.to_python(value)
File "django/db/models/fields/__init__.py", line 2330, in to_python
params={'value': value},
}}}
Ok, so what's going on near line 2330 in
`django/db/models/fields/__init__.py` in the `to_python` function?
{{{
2325: return uuid.UUID(value)
2326: except (AttributeError, ValueError):
2327: raise exceptions.ValidationError(
2328: self.error_messages['invalid'],
2329: code='invalid',
2330: params={'value': value},
2331: )
2332: return value
2333: def formfield(self, **kwargs):
2334: return super().formfield(**{
}}}
And what's going on one frame before that, near line 2316 in
`django/db/models/fields/__init__.py` in `get_db_prep_value`:
{{{
2312: def get_db_prep_value(self, value, connection, prepared=False):
2313: if value is None:
2314: return None
2315: if not isinstance(value, uuid.UUID):
2316: value = self.to_python(value)
2317: if connection.features.has_native_uuid_field:
2318: return value
2319: return value.hex
}}}
Ok, so what's happening is that if the value that we're trying to convert
is not an instance of `uuid.UUID`, then we convert it to a Python value,
which calls `to_python`. This makes sense if `value` is a string, but...
Sentry is telling me that `value` ''is already'' a UUID:
`value UUID('f0c9eb37-a073-47b5-bbb1-589920939c5e')`
The check on line 2315 in `get_db_prep_value` should catch the fact that
this is a UUID, but it doesn't. I don't understand why at all. Sentry is
telling me that this is a UUID but it's failing the instance check; as a
result line 2325 in `to_python` attempts to convert the value to a UUID,
but `value` is already a UUID, so it throws a `ValidationError`.
That's the details of the error. The very weird thing about it is that
this error is totally inconsistent in when it shows up. We'll be running
for days in a production environment without any problems and then all of
a sudden this error will crop up. Once that happens, any attempt to
deserialize a UUID fails with this error.
We are running our application on an EC2 instance in AWS managed by
Elastic Beanstalk. A deployment of the application, which restarts it,
makes this error go away. But sooner or later it crops up again and brings
everything down. The worst thing is that I can't seem to replicate this
error in local development. Our DB runs on an RDS instance and I can point
my local development environment to that DB but I can't replicate the
error.
I'm truly baffled by this. Does anyone have any idea how this can happen?
It very much ''seems'' like a bug to me, hence this report, but I honestly
don't know. I'm just hoping to get some guidance or ideas about what is
going on here.
--
Ticket URL: <https://code.djangoproject.com/ticket/30114>
Django <https://code.djangoproject.com/>
The Web framework for perfectionists with deadlines.
Django
-------------------------------------+-------------------------------------
Type: Bug | Status: new
Component: Database layer | Version: 2.1
(models, ORM) |
Severity: Normal | Resolution:
Keywords: validationerror, | Triage Stage:
uuid | Unreviewed
Has patch: 0 | Needs documentation: 0
Needs tests: 0 | Patch needs improvement: 0
Easy pickings: 0 | UI/UX: 0
-------------------------------------+-------------------------------------
* Attachment "Screenshot_20190117_202331.png" added.
sentry screenshot
Django
-------------------------------------+-------------------------------------
Type: Bug | Status: new
Component: Database layer | Version: 2.1
(models, ORM) |
Severity: Normal | Resolution:
Keywords: validationerror, | Triage Stage:
uuid | Unreviewed
Needs tests: 0 | Patch needs improvement: 0
Easy pickings: 0 | UI/UX: 0
-------------------------------------+-------------------------------------
Comment (by Simon Charette):
This seems to be a continuation of this
[https://groups.google.com/forum/#!searchin/django-users/uuid|sort:date
/django-users/WckmhBJZKxE/BDAUTCvGAQAJ django-users thread]
Did you have a look at [https://groups.google.com/forum/#!msg/django-
users/ZGb8ofw1Ux8/TnMdqsj4AgAJ this other thread] Tim pointed at?
That seems to be an issue with `mod_wsgi`'s use of sub interpreters to me
[https://github.com/GrahamDumpleton/mod_wsgi/issues/206 as pointed out by
the last post]. Are you not using `mod_wsgi`? You specified you were
running on EC2/AWS but nothing about your WSGI server.
--
Ticket URL: <https://code.djangoproject.com/ticket/30114#comment:1>
Django
-------------------------------------+-------------------------------------
Type: Bug | Status: new
Component: Database layer | Version: 2.1
(models, ORM) |
Severity: Normal | Resolution:
Keywords: validationerror, | Triage Stage:
uuid | Unreviewed
Needs tests: 0 | Patch needs improvement: 0
Easy pickings: 0 | UI/UX: 0
-------------------------------------+-------------------------------------
Comment (by Jerry Vinokurov):
Thanks for the pointers, Simon. I am in fact using `mod_wsgi` 4.4.21. I
have been googling this error for a while but wasn't able to find these
threads, so I greatly appreciate that.
--
Ticket URL: <https://code.djangoproject.com/ticket/30114#comment:2>
Django
-------------------------------------+-------------------------------------
Type: Bug | Status: new
Component: Database layer | Version: 2.1
(models, ORM) |
Severity: Normal | Resolution:
Keywords: validationerror, | Triage Stage:
uuid | Unreviewed
Needs tests: 0 | Patch needs improvement: 0
Easy pickings: 0 | UI/UX: 0
-------------------------------------+-------------------------------------
Comment (by Jerry Vinokurov):
I guess I should say, yes, one of those threads is mine. I actually didn't
realize I had gotten any responses to it, maybe the email went to spam or
something.
--
Ticket URL: <https://code.djangoproject.com/ticket/30114#comment:3>
Django
-------------------------------------+-------------------------------------
Type: Bug | Status: new
Component: Database layer | Version: 2.1
(models, ORM) |
Severity: Normal | Resolution:
Keywords: validationerror, | Triage Stage:
uuid | Unreviewed
Needs tests: 0 | Patch needs improvement: 0
Easy pickings: 0 | UI/UX: 0
-------------------------------------+-------------------------------------
Comment (by Keryn Knight):
Having experienced this exact issue in Production a couple of years ago
(Django 1.9ish), also using mod_wsgi, after similar deep-diving to those
threads (wish I'd found them, but I think the problem pre-dated the
mod_wsgi issue, at least) I think the answer for us was to use
`WSGIApplicationGroup %{GLOBAL}` and it resolved the issue. AFAIK there
was nothing in Django at fault, and nothing Django could ''do'' to fix or
even warn about it.
--
Ticket URL: <https://code.djangoproject.com/ticket/30114#comment:4>
Django
-------------------------------------+-------------------------------------
Component: Database layer | Version: 2.1
(models, ORM) |
Keywords: validationerror, | Triage Stage:
uuid | Unreviewed
Needs tests: 0 | Patch needs improvement: 0
Easy pickings: 0 | UI/UX: 0
-------------------------------------+-------------------------------------
* status: new => closed
* resolution: => invalid
Comment:
I'm going to close this as invalid. Will reopen if an example project
showing Django is at fault is presented. (Which doesn't look likely.)
Thanks Simon and Keryn for your help but Jerry, please in future don't use
the issue tracker as a secondary support channel. You did the right thing
posting to Django Users. The correct thing after that was to follow-up
there. (Don't worry about it now. 🙂)
--
Ticket URL: <https://code.djangoproject.com/ticket/30114#comment:5>
Django
-------------------------------------+-------------------------------------
Reporter: Jerry Vinokurov | Owner: nobody
Type: Bug | Status: closed
Component: Database layer | Version: 2.1
(models, ORM) |
Severity: Normal | Resolution: invalid
Keywords: validationerror, | Triage Stage:
uuid | Unreviewed
Needs tests: 0 | Patch needs improvement: 0
Easy pickings: 0 | UI/UX: 0
-------------------------------------+-------------------------------------
--
Ticket URL: <https://code.djangoproject.com/ticket/30114#comment:6>
Django
-------------------------------------+-------------------------------------
Reporter: Jerry Vinokurov | Owner: nobody
Component: Database layer | Version: 2.1
(models, ORM) |
Severity: Normal | Resolution:
uuid | Unreviewed
Needs tests: 0 | Patch needs improvement: 0
Easy pickings: 0 | UI/UX: 0
-------------------------------------+-------------------------------------
* status: closed => new
* resolution: invalid =>
Comment:
We got a similar problem with the same cause on every call to a view using
a model with an UUIDField which is the foreignkey for an other model.
It seams {{{value}}} in 'get_db_prep_value'
(django/db/models/fields/__init__.py) is an UUID object but not of
instance {{{uuid.UUID}}} as described above.
The stack trace:
{{{
File "/opt/python/run/venv/local/lib/python3.6/site-
packages/django/db/models/fields/__init__.py" in to_python
2343. return uuid.UUID(**{input_form: value})
File "/usr/lib64/python3.6/uuid.py" in __init__
137. hex = hex.replace('urn:', '').replace('uuid:', '')
During handling of the above exception ('UUID' object has no attribute
'replace'), another exception occurred:
File "/opt/python/run/venv/local/lib/python3.6/site-
packages/django/core/handlers/exception.py" in inner
34. response = get_response(request)
File "/opt/python/run/venv/local/lib/python3.6/site-
packages/django/core/handlers/base.py" in _get_response
115. response =
self.process_exception_by_middleware(e, request)
File "/opt/python/run/venv/local/lib/python3.6/site-
packages/django/core/handlers/base.py" in _get_response
113. response = wrapped_callback(request,
*callback_args, **callback_kwargs)
File "/opt/python/run/venv/local/lib/python3.6/site-
packages/django/contrib/auth/decorators.py" in _wrapped_view
21. return view_func(request, *args, **kwargs)
[Template Render Call]
File "/opt/python/run/venv/local/lib/python3.6/site-
packages/django/shortcuts.py" in render
36. content = loader.render_to_string(template_name, context,
request, using=using)
File "/opt/python/run/venv/local/lib/python3.6/site-
packages/django/template/loader.py" in render_to_string
62. return template.render(context, request)
File "/opt/python/run/venv/local/lib/python3.6/site-
packages/django/template/backends/django.py" in render
61. return self.template.render(context)
File "/opt/python/run/venv/local/lib/python3.6/site-
packages/django/template/base.py" in render
171. return self._render(context)
File "/opt/python/run/venv/local/lib/python3.6/site-
packages/django/template/base.py" in _render
163. return self.nodelist.render(context)
File "/opt/python/run/venv/local/lib/python3.6/site-
packages/django/template/base.py" in render
937. bit = node.render_annotated(context)
File "/opt/python/run/venv/local/lib/python3.6/site-
packages/django/template/base.py" in render_annotated
904. return self.render(context)
File "/opt/python/run/venv/local/lib/python3.6/site-
packages/django/template/loader_tags.py" in render
150. return compiled_parent._render(context)
File "/opt/python/run/venv/local/lib/python3.6/site-
packages/django/template/base.py" in _render
163. return self.nodelist.render(context)
File "/opt/python/run/venv/local/lib/python3.6/site-
packages/django/template/base.py" in render
937. bit = node.render_annotated(context)
File "/opt/python/run/venv/local/lib/python3.6/site-
packages/django/template/base.py" in render_annotated
904. return self.render(context)
File "/opt/python/run/venv/local/lib/python3.6/site-
packages/django/template/loader_tags.py" in render
62. result = block.nodelist.render(context)
File "/opt/python/run/venv/local/lib/python3.6/site-
packages/django/template/base.py" in render
937. bit = node.render_annotated(context)
File "/opt/python/run/venv/local/lib/python3.6/site-
packages/django/template/base.py" in render_annotated
904. return self.render(context)
File "/opt/python/run/venv/local/lib/python3.6/site-
packages/django/template/defaulttags.py" in render
166. len_values = len(values)
File "/opt/python/run/venv/local/lib/python3.6/site-
packages/django/db/models/query.py" in __len__
256. self._fetch_all()
File "/opt/python/run/venv/local/lib/python3.6/site-
packages/django/db/models/query.py" in _fetch_all
1242. self._result_cache =
list(self._iterable_class(self))
File "/opt/python/run/venv/local/lib/python3.6/site-
packages/django/db/models/query.py" in __iter__
55. results =
compiler.execute_sql(chunked_fetch=self.chunked_fetch,
chunk_size=self.chunk_size)
File "/opt/python/run/venv/local/lib/python3.6/site-
packages/django/db/models/sql/compiler.py" in execute_sql
1127. sql, params = self.as_sql()
File "/opt/python/run/venv/local/lib/python3.6/site-
packages/django/db/models/sql/compiler.py" in as_sql
489. where, w_params = self.compile(self.where) if
self.where is not None else ("", [])
File "/opt/python/run/venv/local/lib/python3.6/site-
packages/django/db/models/sql/compiler.py" in compile
405. sql, params = node.as_sql(self, self.connection)
File "/opt/python/run/venv/local/lib/python3.6/site-
packages/django/db/models/sql/where.py" in as_sql
81. sql, params = compiler.compile(child)
File "/opt/python/run/venv/local/lib/python3.6/site-
packages/django/db/models/sql/compiler.py" in compile
405. sql, params = node.as_sql(self, self.connection)
File "/opt/python/run/venv/local/lib/python3.6/site-
packages/django/db/models/fields/related_lookups.py" in as_sql
130. return super().as_sql(compiler, connection)
File "/opt/python/run/venv/local/lib/python3.6/site-
packages/django/db/models/lookups.py" in as_sql
163. rhs_sql, rhs_params = self.process_rhs(compiler,
connection)
File "/opt/python/run/venv/local/lib/python3.6/site-
packages/django/db/models/lookups.py" in process_rhs
260. return super().process_rhs(compiler, connection)
File "/opt/python/run/venv/local/lib/python3.6/site-
packages/django/db/models/lookups.py" in process_rhs
95. return self.get_db_prep_lookup(value, connection)
File "/opt/python/run/venv/local/lib/python3.6/site-
packages/django/db/models/lookups.py" in get_db_prep_lookup
187. [get_db_prep_value(value, connection, prepared=True)]
File "/opt/python/run/venv/local/lib/python3.6/site-
packages/django/db/models/fields/related.py" in get_db_prep_value
940. return self.target_field.get_db_prep_value(value,
connection, prepared)
File "/opt/python/run/venv/local/lib/python3.6/site-
packages/django/db/models/fields/__init__.py" in get_db_prep_value
2333. value = self.to_python(value)
File "/opt/python/run/venv/local/lib/python3.6/site-
packages/django/db/models/fields/__init__.py" in to_python
2348. params={'value': value},
}}}
We get the same error when query-caching comes into play:
{{{
File "/opt/python/run/venv/local/lib/python3.6/site-
packages/django/db/models/fields/related_descriptors.py" in __get__
164. rel_obj = self.field.get_cached_value(instance)
File "/opt/python/run/venv/local/lib/python3.6/site-
packages/django/db/models/fields/mixins.py" in get_cached_value
13. return instance._state.fields_cache[cache_name]
During handling of the above exception ('user'), another exception
occurred:
File "/opt/python/run/venv/local/lib/python3.6/site-
packages/django/db/models/fields/__init__.py" in to_python
2343. return uuid.UUID(**{input_form: value})
File "/usr/lib64/python3.6/uuid.py" in __init__
137. hex = hex.replace('urn:', '').replace('uuid:', '')
During handling of the above exception ('UUID' object has no attribute
'replace'), another exception occurred:
[...]
}}}
May this have to do with the caching-framework somehow?
Maybe the UUID class created by the cache-deserializer differ from
uuid.UUID?
We are using
* django 2.2.12
* python 3.6.10
* wsgi 1.0
* mod_wsgi 3.5
* 15 theads
* running on an EC2 instances with Amazon Linux/2.9.6
* with postgres-SQL 11.5
The problem suddenly occurred after we disabled our AWS-loadbalancing and
moved from multible instances to one single instance with its own ssl-
proxy.
That why I first thought it's an wsgi issue as said above.
But: The problem does not occur with the same wsgi version and
configuration but with a different django and python version:
* django 1.11.29
* python 3.4
* wsgi 1.0
* mod_wsgi 3.5
* 15 theads
* running on an EC2 instances with Amazon Linux/2.9.6
* with postgres-SQL 9.5.10
WSGI Setup:
{{{
[..]
SSLEngine on
SSLCertificateFile [..]
SSLCertificateKeyFile [..]
[..]
WSGIDaemonProcess wsgi-ssl processes=1 threads=15 display-
name=%{GROUP} \
python-home=/opt/python/run/venv \
python-path=/opt/python/current/app \
home=/opt/python/current/app \
user=wsgi \
group=wsgi
[..]
}}}
For now we are using the following bad hotfix which simply enforces a
string conversion before putting the value into the UUID constructor:
{{{
from django.core import exceptions
from django.db import models
import uuid
class FixedUUIDField(models.UUIDField):
def __init__(self, *args, **kwargs):
super().__init__(*args, **kwargs)
def to_python(self, value):
if value is not None and not isinstance(value, uuid.UUID):
'''
original code:
input_form = 'int' if isinstance(value, int) else 'hex'
try:
return uuid.UUID(**{input_form: str(value)})
'''
try:
if isinstance(value, int):
return uuid.UUID(int=value)
else:
return uuid.UUID(hex=str(value))
except (AttributeError, ValueError):
raise exceptions.ValidationError(
self.error_messages['invalid'],
code='invalid',
params={'value': value},
)
return value
}}}
--
Ticket URL: <https://code.djangoproject.com/ticket/30114#comment:7>
Django
-------------------------------------+-------------------------------------
Reporter: Jerry Vinokurov | Owner: nobody
Component: Database layer | Version: 2.1
(models, ORM) |
Keywords: validationerror, | Triage Stage:
uuid | Unreviewed
Needs tests: 0 | Patch needs improvement: 0
Easy pickings: 0 | UI/UX: 0
-------------------------------------+-------------------------------------
* status: new => closed
* resolution: => invalid
Comment:
Hi @treager — sorry you're hitting problems here, but I can't see anything
that pins down an issue in Django. (There's just too many variables in the
two set-ups you describe to see that that's the case.)
Please see the comments and links preceding
[https://code.djangoproject.com/ticket/30114#comment:4 Keryn's
conclusion]:
> AFAIK there was nothing in Django at fault, and nothing Django could do
to fix or even warn about it.
Then, you decribe this:
> ... is an UUID object but not of instance uuid.UUID as described above.
In normal play, how is this possible?:
What we need to be able to address this (if there's an issue in Django) is
a minimal reproduce project that shows this coming up.
I hope that makes sense. Thanks.
--
Ticket URL: <https://code.djangoproject.com/ticket/30114#comment:8>