magfest / ubersystem

MAGFest's Ubersystem - handles ticketing, staffing, analytics, volunteers, and tons more
http://magfest.org
GNU Affero General Public License v3.0
48 stars 55 forks source link

Preregistration index page throws 500 error #2373

Closed RobRuana closed 7 years ago

RobRuana commented 7 years ago

I believe this is coming from the fact that we avoid saving unpaid attendees in the database by storing them in the session. Please correct me if I'm wrong.

In order to save the prereg in the session, we convert the Attendee into a dict with to_sessionized. Then we later attempt to convert the dict back into an Attendee using from_sessionized.

The error occurs because to_sessionized is serializing readonly properties, like full_name and last_first, and then from_sessionized is attempting to set readonly properties on the new model instance.

I think we can fix this without changing the preregistration code by modifying the MagModel constructor to remove readonly properties from kwargs.

500 Internal Server Error

The server encountered an unexpected condition which prevented it from fulfilling the request.

Traceback (most recent call last):
  File "/home/vagrant/uber/sideboard/env/lib/python3.4/site-packages/cherrypy/_cprequest.py", line 670, in respond
    response.body = self.handler()
  File "/home/vagrant/uber/sideboard/env/lib/python3.4/site-packages/cherrypy/lib/encoding.py", line 220, in __call__
    self.body = self.oldhandler(*args, **kwargs)
  File "/home/vagrant/uber/sideboard/env/lib/python3.4/site-packages/cherrypy/_cpdispatch.py", line 60, in __call__
    return self.callable(*self.args, **self.kwargs)
  File "/home/vagrant/uber/sideboard/plugins/uber/uber/decorators.py", line 238, in with_timing
    return func(*args, **kwargs)
  File "/home/vagrant/uber/sideboard/plugins/uber/uber/decorators.py", line 229, in with_caching
    return func(*args, **kwargs)
  File "/home/vagrant/uber/sideboard/plugins/uber/uber/decorators.py", line 249, in with_session
    return func(*args, **kwargs)
  File "/home/vagrant/uber/sideboard/plugins/uber/uber/decorators.py", line 369, in with_restrictions
    return func(*args, **kwargs)
  File "/home/vagrant/uber/sideboard/plugins/uber/uber/decorators.py", line 318, in with_rendering
    result = func(*args, **kwargs)
  File "/home/vagrant/uber/sideboard/plugins/uber/uber/site_sections/preregistration.py", line 23, in wrapped
    return func(self, *args, **kwargs)
  File "/home/vagrant/uber/sideboard/plugins/uber/uber/decorators.py", line 51, in with_check
    return func(*args, **kwargs)
  File "/home/vagrant/uber/sideboard/plugins/uber/uber/site_sections/preregistration.py", line 94, in index
    'charge': Charge(listify(self.unpaid_preregs.values()))
  File "/home/vagrant/uber/sideboard/plugins/uber/uber/utils.py", line 216, in __init__
    self._models_cached = [self.from_sessionized(d) for d in self.targets]
  File "/home/vagrant/uber/sideboard/plugins/uber/uber/utils.py", line 216, in <listcomp>
    self._models_cached = [self.from_sessionized(d) for d in self.targets]
  File "/home/vagrant/uber/sideboard/plugins/uber/uber/utils.py", line 237, in from_sessionized
    return sa.Session.resolve_model(d['_model'])(**d)
  File "<string>", line 4, in __init__
  File "/home/vagrant/uber/sideboard/env/lib/python3.4/site-packages/sqlalchemy/orm/state.py", line 414, in _initialize_instance
    manager.dispatch.init_failure(self, args, kwargs)
  File "/home/vagrant/uber/sideboard/env/lib/python3.4/site-packages/sqlalchemy/util/langhelpers.py", line 60, in __exit__
    compat.reraise(exc_type, exc_value, exc_tb)
  File "/home/vagrant/uber/sideboard/env/lib/python3.4/site-packages/sqlalchemy/util/compat.py", line 187, in reraise
    raise value
  File "/home/vagrant/uber/sideboard/env/lib/python3.4/site-packages/sqlalchemy/orm/state.py", line 411, in _initialize_instance
    return manager.original_init(*mixed[1:], **kwargs)
  File "/home/vagrant/uber/sideboard/plugins/uber/uber/models.py", line 157, in __init__
    default_constructor(self, *args, **kwargs)
  File "/home/vagrant/uber/sideboard/env/lib/python3.4/site-packages/sqlalchemy/ext/declarative/base.py", line 654, in _declarative_constructor
    setattr(self, k, kwargs[k])
  File "/home/vagrant/uber/sideboard/sideboard/lib/sa/_crud.py", line 1463, in __setattr__
    object.__setattr__(self, name, value)
  File "/home/vagrant/uber/sideboard/env/lib/python3.4/site-packages/sqlalchemy/ext/hybrid.py", line 748, in __set__
    raise AttributeError("can't set attribute")
AttributeError: can't set attribute
kitsuta commented 7 years ago

The most confusing bit about this is that, obviously, we weren't have a problem with this earlier in the year. The to_sessionized and from_sessionized code has been around for literally years. I'm personally not sure what could have changed to break the code this way. To make matters worse, using git bisect proves to be very difficult due to the other huge changes the code has undergone recently.

I have to wonder if something in https://github.com/magfest/sideboard/pull/27 might have caused this -- it was merged after the end of MAGFest 2017, after all, and might be affecting things unexpectedly behind the scenes.

daredoes commented 7 years ago

I agree with your understanding of the conversion of the Attendee using to_sessionized and from_sessionized. Your solution sounds appropriate to me. I hope the implementation goes smoothly.

RobRuana commented 7 years ago

I just looked through magfest/sideboard#27 and I didn't see anything that would have caused this. It's a big pull request, so I could have overlooked something.

It is puzzling that this has only just now cropped up. Good incentive to get automated tests running :)

EliAndrewC commented 7 years ago

I also have no idea why this would have suddenly cropped up. Very strange!

I just did a git diff on the MAGFest codebase from now back to the end of the fest and didn't see anything. I also did a similar git diff on the Sideboard repo and also didn't see anything.

Actually on my local repo I don't see any readonly properties showing up in .to_dict() when I say

>>> Attendee().to_dict()
{'nonshift_hours': 0, '_model': 'Attendee', 'address2': '', 'amount_refunded': 0, 'payment_method': None, 'badge_num': None, 'zip_code': '', 'birthdate': None, 'first_name': '', 'badge_type': 51352218, 'assigned_depts': '', 'reg_station': None, 'paid': 121378471, 'interests': '', 'amount_extra': 0, 'staffing': False, 'affiliate': '', 'can_work_teardown': False, 'hotel_eligible': False, 'address1': '', 'checked_in': None, 'ribbon': 154973361, 'extra_donation': 0, 'region': '', 'overridden_price': None, 'ec_phone': '', 'got_merch': False, 'registered': None, 'country': '', 'watchlist_id': None, 'can_work_setup': False, 'international': False, 'group_id': None, 'extra_merch': '', 'regdesk_info': '', 'city': '', 'email': '', 'can_spam': False, 'for_review': '', 'badge_printed_name': '', 'no_cellphone': False, 'badge_status': 163076611, 'trusted_depts': '', 'found_how': '', 'requested_depts': '', 'last_name': '', 'cellphone': '', 'past_years': '', 'public_id': 'b664062b-c319-4b2d-9606-10d030b481cc', 'admin_notes': '', 'placeholder': False, 'age_group': 178244408, 'comments': '', 'ec_name': '', 'shirt': 0, 'amount_paid': 0, 'id': '6c1eb3e7-1f60-4768-8b53-7ef99b0fd82d'}

This explains why it hasn't been happening, but I have the latest code from all the repos and I still don't see any readonly properties showing up in the dicts. I've also tried running .from_dict() on the result of a .to_dict() and it still works as I expect.

RobRuana commented 7 years ago

Welp, I definitely do see readonly fields :(

>>> Attendee().to_dict()
{'watchlist_id': None, 'can_spam': False, 'registered': None, 'admin_notes': '', 'group_id': None, 'paid': 121378471, 'amount_paid': 0, 'id': '497edc53-c793-4d79-8671-8c6c374ecfd3', 'zip_code': '', 'can_work_teardown': False, 'overridden_price': None, 'cellphone': '', 'site_type': None, 'ribbon': 154973361, 'past_years': '', 'ec_name': '', 'ec_phone': '', 'address1': '', 'for_review': '', 'email': '', 'birthdate': None, 'interests': '', 'checked_in': None, 'trusted_depts': '', 'badge_num': None, 'found_how': '', 'age_group': 178244408, 'amount_refunded': 0, 'shirt': 0, 'can_work_setup': False, 'no_cellphone': False, 'coming_with': '', 'purchased_food': False, 'last_name': '', 'badge_type': 51352218, '_model': 'Attendee', 'comments': '', 'assigned_depts': '', 'requested_depts': '', 'nonshift_hours': 0, 'public_id': '7fa12850-8461-401d-a7df-2a9a34731cc4', 'international': False, 'staffing': False, 'payment_method': None, 'badge_printed_name': '', 'camping_type': None, 'placeholder': False, 'country': '', 'coming_as': None, 'full_name': ' ', 'site_number': None, 'allergies': '', 'reg_station': None, 'regdesk_info': '', 'city': '', 'region': '', 'noise_level': None, 'extra_merch': '', 'first_name': '', 'address2': '', 'badge_status': 163076611, 'amount_extra': 0, 'got_merch': False, 'last_first': ', ', 'license_plate': '', 'affiliate': ''}

Notably last_first and full_name are showing up. Are we perhaps on different versions of libraries?

$ python --version
Python 3.4.3
$ pip freeze
alabaster==0.7.10
alembic==0.8.7
appdirs==1.4.2
Babel==2.3.4
-e git+https://github.com/magfest/bands@cdea319d41fb5fe1ea4c32be1049d621633f19d4#egg=bands
-e git+https://github.com/rams/barcode@3fa07399f8b6cdfe31a82e9e927f0657fab042e1#egg=barcode
CherryPy==8.9.1
configobj==5.0.6
coverage==4.3.4
Django==1.6.1
dnspython==1.15.0
docutils==0.13.1
email-validator==1.0.2
geopy==1.11.0
idna==2.4
imagesize==0.7.1
Jinja2==2.9.5
logging-unterpolation==0.2.0
-e git+https://github.com/magfest/magfest@7a432de9e4ca96c36e1e98e8c545358cff5548f6#egg=magfest
-e git+https://github.com/magfest/magstock@f0a596acc29baddc9610d62123bd768886fc3463#egg=magstock
Mako==1.0.6
MarkupSafe==0.23
mock==1.0.1
olefile==0.44
packaging==16.8
-e git+https://github.com/magfest/panels@b141b52f4c6dc7bc53cbe9f3eea0e53541f9795a#egg=panels
Paver==1.2.4
pep8==1.6.2
Pillow==4.0.0
psycopg2==2.5.2
py==1.4.32
py3k-bcrypt==0.3
Pygments==2.2.0
pyparsing==2.2.0
pytest==3.0.6
python-editor==1.0.3
pytz==2014.4
-e git+https://github.com/magfest/reports@f8fb4fb3ce20be18afaf92801f185cd98d32484a#egg=reports
requests==2.13.0
rpctools==0.3.1
sh==1.12.10
-e git+https://github.com/magfest/sideboard@698dcfd10641a243541fc4d482538dd8a02c2100#egg=sideboard
six==1.10.0
snowballstemmer==1.2.1
Sphinx==1.5.3
SQLAlchemy==1.1.6
stripe==1.11.0
treepoem==1.0.1
-e git+git@github.com:robruana/ubersystem.git@4c27ab6223e18a806c929d0c09299336048f0283#egg=uber
-e git+https://github.com/magfest/uber_analytics@7d095dbee26c2bf946d1d4b9f80c0ca750df63bc#egg=uber_analytics
uszipcode==0.1.3
ws4py==0.3.5
RobRuana commented 7 years ago

It's cool, I have a fix for it. Need to write tests before I issue a pullreq, but that'll have to wait for tomorrow :)

EliAndrewC commented 7 years ago

Interesting - looks like I'm on some older library versions. I'm going to guess that this is SQLAlchemy which is the culprit, so let me try upgrading that specifically from 1.0.0 which is what I happened to be on before to 1.1.6 which is what you're on...

Yep, that did it! So apparently there was a backwards-incompatible change in SQLAlchemy between 1.0.0 which is what we were on before (I checked our production server and that's also what we were on) and 1.1.6 which is the latest.

Here's my guess: the to_dict_default_attrs method (https://github.com/magfest/sideboard/blob/master/sideboard/lib/sa/_crud.py#L1268) which basically grabs all of the ColumnProperty fields. Our full_name and last_first fields are defined using @hybrid_property and I'm guessing that sometime between version 1.0 and now then those properties started tripping that check.

Regardless: the fix Rob proposes is good for this repo, but in the long run we should probably also fix the Sideboard .to_dict() so that it doesn't emit hybrid properties, since that was the old, correct behavior.

RobRuana commented 7 years ago

I've done some work on this in the model constructor, but I think you're right that the better place to put the check is to_dict_default_attrs.

I'll do that tomorrow :)

kitsuta commented 7 years ago

Excellent sleuthing! :D

bds002 commented 7 years ago

One other thing to check, the DB may need a reset on the deployed servers because we may have made recent schema changes without a migration. Might be unrelated to this bug though.

And yea the current wave of new servers use Eli's upstream sideboard changes which include new versions of requirements.txt so there may be some incompatiblies we just introduced and haven't discovered yet

On Mar 7, 2017 3:15 AM, "Victoria Earl" notifications@github.com wrote:

Excellent sleuthing! :D

— You are receiving this because you are subscribed to this thread. Reply to this email directly, view it on GitHub https://github.com/magfest/ubersystem/issues/2373#issuecomment-284652104, or mute the thread https://github.com/notifications/unsubscribe-auth/AIaeSuAALuAFMq8gV7LQ9gijjii9c6Paks5rjRIfgaJpZM4MU77- .

RobRuana commented 7 years ago

I should note, the above sideboard PR fixes the issue, BUT you will have to delete your session data if it already has corrupt data in it.