pretalx becomes unusable "pretalx.schedule.models.schedule.MultipleObjectsReturned: get() returned more than one Schedule -- it returned 2!"

[laf0rge]

Expected Behavior

Normally I'd expect the pretalx orga interface for schedule adjustments when looking at e.g. https://pretalx.sysmocom.de/orga/event/osmocon2018/schedule/

Current Behavior

pretalx displays https://pretalx.sysmocom.de/static/common/img/error_5xx.5baae707387f.svg in the browser and adds the following to the log:

pretalx_1             | ERROR 2018-10-12 08:42:19,042 django.request exception Internal Server Error: /orga/event/osmocon2018/schedule/
pretalx_1             | Traceback (most recent call last):
pretalx_1             |   File "/usr/local/lib/python3.6/site-packages/django/core/handlers/exception.py", line 35, in inner
pretalx_1             |     response = get_response(request)
pretalx_1             |   File "/usr/local/lib/python3.6/site-packages/django/core/handlers/base.py", line 128, in _get_response
pretalx_1             |     response = self.process_exception_by_middleware(e, request)
pretalx_1             |   File "/usr/local/lib/python3.6/site-packages/django/core/handlers/base.py", line 126, in _get_response
pretalx_1             |     response = wrapped_callback(request, *callback_args, **callback_kwargs)
pretalx_1             |   File "/usr/local/lib/python3.6/site-packages/django/views/generic/base.py", line 69, in view
pretalx_1             |     return self.dispatch(request, *args, **kwargs)
pretalx_1             |   File "/usr/local/lib/python3.6/site-packages/django/utils/decorators.py", line 62, in _wrapper
pretalx_1             |     return bound_func(*args, **kwargs)
pretalx_1             |   File "/usr/local/lib/python3.6/site-packages/csp/decorators.py", line 19, in _wrapped
pretalx_1             |     r = f(*a, **kw)
pretalx_1             |   File "/usr/local/lib/python3.6/site-packages/django/utils/decorators.py", line 58, in bound_func
pretalx_1             |     return func.__get__(self, type(self))(*args2, **kwargs2)
pretalx_1             |   File "/usr/local/lib/python3.6/site-packages/django/contrib/auth/mixins.py", line 85, in dispatch
pretalx_1             |     return super().dispatch(request, *args, **kwargs)
pretalx_1             |   File "/usr/local/lib/python3.6/site-packages/django/views/generic/base.py", line 89, in dispatch
pretalx_1             |     return handler(request, *args, **kwargs)
pretalx_1             |   File "/usr/local/lib/python3.6/site-packages/django/views/generic/base.py", line 150, in get
pretalx_1             |     context = self.get_context_data(**kwargs)
pretalx_1             |   File "/src/pretalx/orga/views/schedule.py", line 44, in get_context_data
pretalx_1             |     context['active_schedule'] = self.request.event.schedules.filter(version=version).first() if version else self.request.event.wip_schedule
pretalx_1             |   File "/usr/local/lib/python3.6/site-packages/django/utils/functional.py", line 36, in __get__
pretalx_1             |     res = instance.__dict__[self.name] = self.func(instance)
pretalx_1             |   File "/src/pretalx/event/models/event.py", line 317, in wip_schedule
pretalx_1             |     schedule, _ = self.schedules.get_or_create(version__isnull=True)
pretalx_1             |   File "/usr/local/lib/python3.6/site-packages/django/db/models/fields/related_descriptors.py", line 629, in get_or_create
pretalx_1             |     return super(RelatedManager, self.db_manager(db)).get_or_create(**kwargs)
pretalx_1             |   File "/usr/local/lib/python3.6/site-packages/django/db/models/manager.py", line 82, in manager_method
pretalx_1             |     return getattr(self.get_queryset(), name)(*args, **kwargs)
pretalx_1             |   File "/usr/local/lib/python3.6/site-packages/django/db/models/query.py", line 487, in get_or_create
pretalx_1             |     return self.get(**lookup), False
pretalx_1             |   File "/usr/local/lib/python3.6/site-packages/django/db/models/query.py", line 407, in get
pretalx_1             |     (self.model._meta.object_name, num)
pretalx_1             | pretalx.schedule.models.schedule.MultipleObjectsReturned: get() returned more than one Schedule -- it returned 2!
pretalx_1             | ERROR 2018-10-12 08:42:19,042 django.request exception Internal Server Error: /orga/event/osmocon2018/schedule/
pretalx_1             | Traceback (most recent call last):
pretalx_1             |   File "/usr/local/lib/python3.6/site-packages/django/core/handlers/exception.py", line 35, in inner
pretalx_1             |     response = get_response(request)
pretalx_1             |   File "/usr/local/lib/python3.6/site-packages/django/core/handlers/base.py", line 128, in _get_response
pretalx_1             |     response = self.process_exception_by_middleware(e, request)
pretalx_1             |   File "/usr/local/lib/python3.6/site-packages/django/core/handlers/base.py", line 126, in _get_response
pretalx_1             |     response = wrapped_callback(request, *callback_args, **callback_kwargs)
pretalx_1             |   File "/usr/local/lib/python3.6/site-packages/django/views/generic/base.py", line 69, in view
pretalx_1             |     return self.dispatch(request, *args, **kwargs)
pretalx_1             |   File "/usr/local/lib/python3.6/site-packages/django/utils/decorators.py", line 62, in _wrapper
pretalx_1             |     return bound_func(*args, **kwargs)
pretalx_1             |   File "/usr/local/lib/python3.6/site-packages/csp/decorators.py", line 19, in _wrapped
pretalx_1             |     r = f(*a, **kw)
pretalx_1             |   File "/usr/local/lib/python3.6/site-packages/django/utils/decorators.py", line 58, in bound_func
pretalx_1             |     return func.__get__(self, type(self))(*args2, **kwargs2)
pretalx_1             |   File "/usr/local/lib/python3.6/site-packages/django/contrib/auth/mixins.py", line 85, in dispatch
pretalx_1             |     return super().dispatch(request, *args, **kwargs)
pretalx_1             |   File "/usr/local/lib/python3.6/site-packages/django/views/generic/base.py", line 89, in dispatch
pretalx_1             |     return handler(request, *args, **kwargs)
pretalx_1             |   File "/usr/local/lib/python3.6/site-packages/django/views/generic/base.py", line 150, in get
pretalx_1             |     context = self.get_context_data(**kwargs)
pretalx_1             |   File "/src/pretalx/orga/views/schedule.py", line 44, in get_context_data
pretalx_1             |     context['active_schedule'] = self.request.event.schedules.filter(version=version).first() if version else self.request.event.wip_schedule
pretalx_1             |   File "/usr/local/lib/python3.6/site-packages/django/utils/functional.py", line 36, in __get__
pretalx_1             |     res = instance.__dict__[self.name] = self.func(instance)
pretalx_1             |   File "/src/pretalx/event/models/event.py", line 317, in wip_schedule
pretalx_1             |     schedule, _ = self.schedules.get_or_create(version__isnull=True)
pretalx_1             |   File "/usr/local/lib/python3.6/site-packages/django/db/models/fields/related_descriptors.py", line 629, in get_or_create
pretalx_1             |     return super(RelatedManager, self.db_manager(db)).get_or_create(**kwargs)
pretalx_1             |   File "/usr/local/lib/python3.6/site-packages/django/db/models/manager.py", line 82, in manager_method
pretalx_1             |     return getattr(self.get_queryset(), name)(*args, **kwargs)
pretalx_1             |   File "/usr/local/lib/python3.6/site-packages/django/db/models/query.py", line 487, in get_or_create
pretalx_1             |     return self.get(**lookup), False
pretalx_1             |   File "/usr/local/lib/python3.6/site-packages/django/db/models/query.py", line 407, in get
pretalx_1             |     (self.model._meta.object_name, num)
pretalx_1             | pretalx.schedule.models.schedule.MultipleObjectsReturned: get() returned more than one Schedule -- it returned 2!

I don't know how I ended up there. Haven't logged into the pretalx instance for several days, and now this.

[laf0rge]

The database looks like this:

pretalx=# select * from schedule_schedule order by event_id;
 id | version | event_id |           published           
----+---------+----------+-------------------------------
  1 |         |        1 | 
 32 |         |        2 | 
  2 | v0.1    |        2 | 2018-08-16 17:07:30.080133+00
 23 | v0.11   |        2 | 2018-08-16 17:30:04.816629+00
 24 | v0.12   |        2 | 2018-08-24 18:04:55.895423+00
 25 | v0.13   |        2 | 2018-08-30 18:47:17.324216+00
 26 | v0.14   |        2 | 2018-09-01 20:29:33.434642+00
 27 | v0.2    |        2 | 2018-09-19 10:44:40.846729+00
 28 | v0.3    |        2 | 2018-09-27 12:46:03.604939+00
 29 | v0.31   |        2 | 2018-09-30 14:56:47.764601+00
 31 |         |        2 | 
 30 | v0.32   |        2 | 2018-10-08 13:59:29.241481+00
 14 | v1.0    |        3 | 2018-04-21 14:20:53.550678+00
 15 | v1.01   |        3 | 2018-04-21 21:32:20.825474+00
 16 | v1.02   |        3 | 2018-04-22 08:02:46.20948+00
 17 | v1.03   |        3 | 2018-04-22 09:46:39.601911+00
 18 | v1.04   |        3 | 2018-04-22 14:11:03.33929+00
 19 | v1.05   |        3 | 2018-04-22 14:42:45.758111+00
 20 | v1.06   |        3 | 2018-04-29 17:38:12.575725+00
 21 |         |        3 | 
 12 | v0.9    |        3 | 2018-04-19 10:16:08.157794+00
 13 | v0.99   |        3 | 2018-04-20 18:32:21.929793+00
  3 | v0.1    |        3 | 2018-04-03 21:19:26.045358+00
  4 | v0.2    |        3 | 2018-04-05 10:02:11.281211+00
  6 | v0.3    |        3 | 2018-04-05 15:07:38.997381+00
  7 | v0.4    |        3 | 2018-04-05 18:11:10.728211+00
  8 | v0.5    |        3 | 2018-04-05 18:38:12.88198+00
  9 | v0.6    |        3 | 2018-04-05 18:44:51.309838+00
 10 | v0.7    |        3 | 2018-04-13 07:19:29.743594+00
 11 | v0.8    |        3 | 2018-04-13 07:25:30.578217+00
  5 |         |        4 | 
 22 |         |        5 | 
(32 rows)

where "2" is the event in question. so basically

pretalx=# select * from schedule_schedule where event_id=2; 
 id | version | event_id |           published           
----+---------+----------+-------------------------------
  2 | v0.1    |        2 | 2018-08-16 17:07:30.080133+00
 23 | v0.11   |        2 | 2018-08-16 17:30:04.816629+00
 24 | v0.12   |        2 | 2018-08-24 18:04:55.895423+00
 25 | v0.13   |        2 | 2018-08-30 18:47:17.324216+00
 26 | v0.14   |        2 | 2018-09-01 20:29:33.434642+00
 27 | v0.2    |        2 | 2018-09-19 10:44:40.846729+00
 28 | v0.3    |        2 | 2018-09-27 12:46:03.604939+00
 29 | v0.31   |        2 | 2018-09-30 14:56:47.764601+00
 30 | v0.32   |        2 | 2018-10-08 13:59:29.241481+00
 32 |         |        2 | 
 31 |         |        2 | 
(11 rows)

which means there are two schedules with no version set so far. I never edited the database, so those two schedules must have been created using the web UI.

[laf0rge]

pretalx=# update schedule_schedule set version='v0.33' where id=31;
UPDATE 1

seems to have helped. Still no idea as to how one manages to get the DB into this state in the first place?

[rixx]

Me neither, but thank you for reporting this, it is definitely a bug. For all other cases, db-level constraints take care of this, but NULL values and unique constraints are not a good match.

[rixx]

The only part of the code that could produce this behaviour as far as I can tell, occurs when the "dirty"/wip schedule is reset to a prior schedule version, and something goes wrong during this method. (The opposite operation was already wrapped in a transaction, seems I missed it for the reversal). I added this and one other safeguard, and I'm reasonably confident that this can't occur again.

[NerdyProjects]

I had the same situation occuring here as well. Same error, two duplicate schedules for an event without a version:

pretalx=> SELECT id,version FROM schedule_schedule WHERE event_id=6;
 id | version 
----+---------
 50 | 0.2
 51 | 0.201
 52 | 0.202
 53 | 0.203
 54 | 0.204
 55 | 0.205
 56 | 0.206
 58 | 0.207
 59 | 0.208
 60 | 0.209
 61 | 0.210
 62 | 0.211
 63 | 0.212
 65 | 
 64 | 0.213
 67 | 
 48 | 0.1
(17 rows)

fixed by manually setting a version.

Running pretalx-2.3.1

[rixx]

I still don't know how this happens – likely a race condition somewhere – but we need to provide a mitigation at the very least.