HTTP Internal Server Error on registration / first use #39

New issue

Closed

opened 2022-07-05 01:38:42 +02:00 by blacklight · 0 comments

blacklight commented

2022-07-05 01:38:42 +02:00

Owner

Initial registration flow:

2021-03-25 08:19:37,360| INFO|werkzeug|10.0.0.2 - - [25/Mar/2021 08:19:37] "GET / HTTP/1.1" 307 -
2021-03-25 08:19:37,409| INFO|werkzeug|10.0.0.2 - - [25/Mar/2021 08:19:37] "GET /register?redirect=http://lipnerpi.local:8008/ HTTP/1.1" 200 -
2021-03-25 08:19:37,658| INFO|werkzeug|10.0.0.2 - - [25/Mar/2021 08:19:37] "POST /execute HTTP/1.1" 307 -
2021-03-25 08:19:37,694| INFO|werkzeug|10.0.0.2 - - [25/Mar/2021 08:19:37] "POST /register?redirect=http://lipnerpi.local:8008/execute HTTP/1.1" 200 -
2021-03-25 08:19:59,048|ERROR|platypush|Exception on /register [POST]
Traceback (most recent call last):
  File "/usr/local/lib/python3.7/dist-packages/flask/app.py", line 2447, in wsgi_app
    response = self.full_dispatch_request()
  File "/usr/local/lib/python3.7/dist-packages/flask/app.py", line 1952, in full_dispatch_request
    rv = self.handle_user_exception(e)
  File "/usr/local/lib/python3.7/dist-packages/flask/app.py", line 1821, in handle_user_exception
    reraise(exc_type, exc_value, tb)
  File "/usr/local/lib/python3.7/dist-packages/flask/_compat.py", line 39, in reraise
    raise value
  File "/usr/local/lib/python3.7/dist-packages/flask/app.py", line 1950, in full_dispatch_request
    rv = self.dispatch_request()
  File "/usr/local/lib/python3.7/dist-packages/flask/app.py", line 1936, in dispatch_request
    return self.view_functions[rule.endpoint](**req.view_args)
  File "/usr/local/lib/python3.7/dist-packages/platypush/backend/http/app/routes/register.py", line 54, in register
    response.set_cookie('session_token', session.session_token)
  File "/usr/local/lib/python3.7/dist-packages/sqlalchemy/orm/attributes.py", line 449, in __get__
    return self.impl.get(state, dict_)
  File "/usr/local/lib/python3.7/dist-packages/sqlalchemy/orm/attributes.py", line 888, in get
    value = state._load_expired(state, passive)
  File "/usr/local/lib/python3.7/dist-packages/sqlalchemy/orm/state.py", line 667, in _load_expired
    self.manager.expired_attribute_loader(self, toload, passive)
  File "/usr/local/lib/python3.7/dist-packages/sqlalchemy/orm/loading.py", line 1330, in load_scalar_attributes
    "attribute refresh operation cannot proceed" % (state_str(state))
sqlalchemy.orm.exc.DetachedInstanceError: Instance <UserSession at 0x72755a10> is not bound to a Session; attribute refresh operation cannot proceed (Background on this error at: http://sqlalche.me/e/14/bhk3)
2021-03-25 08:19:59,058| INFO|werkzeug|10.0.0.2 - - [25/Mar/2021 08:19:59] "POST /register?redirect=http://lipnerpi.local:8008/ HTTP/1.1" 500 -

Following logins:

"GET / HTTP/1.1" 307 -
2021-03-25 08:21:53,443| INFO|werkzeug|10.0.0.2 - - [25/Mar/2021 08:21:53] "GET /login?redirect=http://lipnerpi.local:8008/ HTTP/1.1" 200 -
2021-03-25 08:21:53,721| INFO|werkzeug|10.0.0.2 - - [25/Mar/2021 08:21:53] "POST /execute HTTP/1.1" 307 -
2021-03-25 08:21:53,750| INFO|werkzeug|10.0.0.2 - - [25/Mar/2021 08:21:53] "POST /login?redirect=http://lipnerpi.local:8008/execute HTTP/1.1" 200 -
2021-03-25 08:22:00,776|ERROR|platypush|Exception on /login [POST]
Traceback (most recent call last):
  File "/usr/local/lib/python3.7/dist-packages/flask/app.py", line 2447, in wsgi_app
    response = self.full_dispatch_request()
  File "/usr/local/lib/python3.7/dist-packages/flask/app.py", line 1952, in full_dispatch_request
    rv = self.handle_user_exception(e)
  File "/usr/local/lib/python3.7/dist-packages/flask/app.py", line 1821, in handle_user_exception
    reraise(exc_type, exc_value, tb)
  File "/usr/local/lib/python3.7/dist-packages/flask/_compat.py", line 39, in reraise
    raise value
  File "/usr/local/lib/python3.7/dist-packages/flask/app.py", line 1950, in full_dispatch_request
    rv = self.dispatch_request()
  File "/usr/local/lib/python3.7/dist-packages/flask/app.py", line 1936, in dispatch_request
    return self.view_functions[rule.endpoint](**req.view_args)
  File "/usr/local/lib/python3.7/dist-packages/platypush/backend/http/app/routes/login.py", line 49, in login
    response.set_cookie('session_token', session.session_token, expires=expires)
  File "/usr/local/lib/python3.7/dist-packages/sqlalchemy/orm/attributes.py", line 449, in __get__
    return self.impl.get(state, dict_)
  File "/usr/local/lib/python3.7/dist-packages/sqlalchemy/orm/attributes.py", line 888, in get
    value = state._load_expired(state, passive)
  File "/usr/local/lib/python3.7/dist-packages/sqlalchemy/orm/state.py", line 667, in _load_expired
    self.manager.expired_attribute_loader(self, toload, passive)
  File "/usr/local/lib/python3.7/dist-packages/sqlalchemy/orm/loading.py", line 1330, in load_scalar_attributes
    "attribute refresh operation cannot proceed" % (state_str(state))
sqlalchemy.orm.exc.DetachedInstanceError: Instance <UserSession at 0x742c2470> is not bound to a Session; attribute refresh operation cannot proceed (Background on this error at: http://sqlalche.me/e/14/bhk3)
2021-03-25 08:22:00,780| INFO|werkzeug|10.0.0.2 - - [25/Mar/2021 08:22:00] "POST /login?redirect=http://lipnerpi.local:8008/ HTTP/1.1" 500 -

I've set up a new Platypush instance. As soon as the initial registration is over, any attempt at login fails with an Error 500. Backend shows error related to the ORM. Platypush is being run as root, but happened when running as non root as well. Board is an RPi 3, running the latest Raspbian 10. Initial registration flow: ``` 2021-03-25 08:19:37,360| INFO|werkzeug|10.0.0.2 - - [25/Mar/2021 08:19:37] "GET / HTTP/1.1" 307 - 2021-03-25 08:19:37,409| INFO|werkzeug|10.0.0.2 - - [25/Mar/2021 08:19:37] "GET /register?redirect=http://lipnerpi.local:8008/ HTTP/1.1" 200 - 2021-03-25 08:19:37,658| INFO|werkzeug|10.0.0.2 - - [25/Mar/2021 08:19:37] "POST /execute HTTP/1.1" 307 - 2021-03-25 08:19:37,694| INFO|werkzeug|10.0.0.2 - - [25/Mar/2021 08:19:37] "POST /register?redirect=http://lipnerpi.local:8008/execute HTTP/1.1" 200 - 2021-03-25 08:19:59,048|ERROR|platypush|Exception on /register [POST] Traceback (most recent call last): File "/usr/local/lib/python3.7/dist-packages/flask/app.py", line 2447, in wsgi_app response = self.full_dispatch_request() File "/usr/local/lib/python3.7/dist-packages/flask/app.py", line 1952, in full_dispatch_request rv = self.handle_user_exception(e) File "/usr/local/lib/python3.7/dist-packages/flask/app.py", line 1821, in handle_user_exception reraise(exc_type, exc_value, tb) File "/usr/local/lib/python3.7/dist-packages/flask/_compat.py", line 39, in reraise raise value File "/usr/local/lib/python3.7/dist-packages/flask/app.py", line 1950, in full_dispatch_request rv = self.dispatch_request() File "/usr/local/lib/python3.7/dist-packages/flask/app.py", line 1936, in dispatch_request return self.view_functions[rule.endpoint](**req.view_args) File "/usr/local/lib/python3.7/dist-packages/platypush/backend/http/app/routes/register.py", line 54, in register response.set_cookie('session_token', session.session_token) File "/usr/local/lib/python3.7/dist-packages/sqlalchemy/orm/attributes.py", line 449, in __get__ return self.impl.get(state, dict_) File "/usr/local/lib/python3.7/dist-packages/sqlalchemy/orm/attributes.py", line 888, in get value = state._load_expired(state, passive) File "/usr/local/lib/python3.7/dist-packages/sqlalchemy/orm/state.py", line 667, in _load_expired self.manager.expired_attribute_loader(self, toload, passive) File "/usr/local/lib/python3.7/dist-packages/sqlalchemy/orm/loading.py", line 1330, in load_scalar_attributes "attribute refresh operation cannot proceed" % (state_str(state)) sqlalchemy.orm.exc.DetachedInstanceError: Instance <UserSession at 0x72755a10> is not bound to a Session; attribute refresh operation cannot proceed (Background on this error at: http://sqlalche.me/e/14/bhk3) 2021-03-25 08:19:59,058| INFO|werkzeug|10.0.0.2 - - [25/Mar/2021 08:19:59] "POST /register?redirect=http://lipnerpi.local:8008/ HTTP/1.1" 500 - ``` Following logins: ``` "GET / HTTP/1.1" 307 - 2021-03-25 08:21:53,443| INFO|werkzeug|10.0.0.2 - - [25/Mar/2021 08:21:53] "GET /login?redirect=http://lipnerpi.local:8008/ HTTP/1.1" 200 - 2021-03-25 08:21:53,721| INFO|werkzeug|10.0.0.2 - - [25/Mar/2021 08:21:53] "POST /execute HTTP/1.1" 307 - 2021-03-25 08:21:53,750| INFO|werkzeug|10.0.0.2 - - [25/Mar/2021 08:21:53] "POST /login?redirect=http://lipnerpi.local:8008/execute HTTP/1.1" 200 - 2021-03-25 08:22:00,776|ERROR|platypush|Exception on /login [POST] Traceback (most recent call last): File "/usr/local/lib/python3.7/dist-packages/flask/app.py", line 2447, in wsgi_app response = self.full_dispatch_request() File "/usr/local/lib/python3.7/dist-packages/flask/app.py", line 1952, in full_dispatch_request rv = self.handle_user_exception(e) File "/usr/local/lib/python3.7/dist-packages/flask/app.py", line 1821, in handle_user_exception reraise(exc_type, exc_value, tb) File "/usr/local/lib/python3.7/dist-packages/flask/_compat.py", line 39, in reraise raise value File "/usr/local/lib/python3.7/dist-packages/flask/app.py", line 1950, in full_dispatch_request rv = self.dispatch_request() File "/usr/local/lib/python3.7/dist-packages/flask/app.py", line 1936, in dispatch_request return self.view_functions[rule.endpoint](**req.view_args) File "/usr/local/lib/python3.7/dist-packages/platypush/backend/http/app/routes/login.py", line 49, in login response.set_cookie('session_token', session.session_token, expires=expires) File "/usr/local/lib/python3.7/dist-packages/sqlalchemy/orm/attributes.py", line 449, in __get__ return self.impl.get(state, dict_) File "/usr/local/lib/python3.7/dist-packages/sqlalchemy/orm/attributes.py", line 888, in get value = state._load_expired(state, passive) File "/usr/local/lib/python3.7/dist-packages/sqlalchemy/orm/state.py", line 667, in _load_expired self.manager.expired_attribute_loader(self, toload, passive) File "/usr/local/lib/python3.7/dist-packages/sqlalchemy/orm/loading.py", line 1330, in load_scalar_attributes "attribute refresh operation cannot proceed" % (state_str(state)) sqlalchemy.orm.exc.DetachedInstanceError: Instance <UserSession at 0x742c2470> is not bound to a Session; attribute refresh operation cannot proceed (Background on this error at: http://sqlalche.me/e/14/bhk3) 2021-03-25 08:22:00,780| INFO|werkzeug|10.0.0.2 - - [25/Mar/2021 08:22:00] "POST /login?redirect=http://lipnerpi.local:8008/ HTTP/1.1" 500 - ```