Opened 5 years ago

Closed 4 years ago

#30114 closed Bug (invalid)

ValidationError sometimes raised for valid UUIDs with mod_wsgi

Reported by: Jerry Vinokurov Owned by: nobody
Component: Database layer (models, ORM) Version: 2.1
Severity: Normal Keywords: validationerror, uuid
Cc: Triage Stage: Unreviewed
Has patch: no Needs documentation: no
Needs tests: no Patch needs improvement: no
Easy pickings: no UI/UX: no

Description

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.

Attachments (1)

Screenshot_20190117_202331.png (94.4 KB ) - added by Jerry Vinokurov 5 years ago.
sentry screenshot

Download all attachments as: .zip

Change History (9)

by Jerry Vinokurov, 5 years ago

sentry screenshot

comment:1 by Simon Charette, 5 years ago

This seems to be a continuation of this django-users thread

Did you have a look at this other thread Tim pointed at?

That seems to be an issue with mod_wsgi's use of sub interpreters to me 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.

comment:2 by Jerry Vinokurov, 5 years ago

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.

comment:3 by Jerry Vinokurov, 5 years ago

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.

comment:4 by Keryn Knight, 5 years ago

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.

comment:5 by Carlton Gibson, 5 years ago

Resolution: invalid
Status: newclosed

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. 🙂)

comment:6 by Tim Graham, 5 years ago

Summary: Strange ValidationError issueValidationError sometimes raised for valid UUIDs with mod_wsgi

comment:7 by traeger, 4 years ago

Resolution: invalid
Status: closednew

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

comment:8 by Carlton Gibson, 4 years ago

Resolution: invalid
Status: newclosed

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 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.

Note: See TracTickets for help on using tickets.
Back to Top