search

overthesun / simoc

A scalable model of an interactive, off-world community
https://ngs.simoc.space/
GNU General Public License v3.0
2 stars 2 forks source link

`new_game` fails with DetachedInstanceError #88

Open ezio-melotti opened 5 years ago

ezio-melotti commented 5 years ago

Request:

{"game_config":{"duration":{"value":100,"type":"hour"},"human_agent":{"amount":4},"food_storage":{"amount":10000},"solar_arrays":{"amount":30},"power_storage":{"amount":1},"eclss":{"amount":1},"single_agent":1,"plants":[{"species":"wheat","amount":50},{"species":"cabbage","amount":50},{"species":"strawberry","amount":50},{"species":"radish","amount":50},{"species":"red_beet","amount":33},{"species":"lettuce","amount":34}],"greenhouse":"greenhouse_small","habitat":"crew_habitat_small"}}

Response:

{"error": "Instance <User at 0x7f8a197ed550> is not bound to a Session; attribute refresh operation cannot proceed (Background on this error at: http://sqlalche.me/e/bhk3)"}

Server log:

flask-app_1      | 2019-08-24T14:28:42.885785125Z [2019-08-24 14:28:42 +0000] [9] [DEBUG] POST /new_game
celery-worker_2  | 2019-08-24T14:28:42.920715224Z [2019-08-24 14:28:42,920: INFO/MainProcess] Received task: celery_worker.tasks.new_game[cbc5c277-a6c8-4d3d-a99e-c2aa1b02d84f]  
celery-worker_2  | 2019-08-24T14:28:42.921392501Z [2019-08-24 14:28:42,921: DEBUG/MainProcess] TaskPool: Apply <function _fast_trace_task at 0x7f8a21a03d08> (args:('celery_worker.tasks.new_game', 'cbc5c277-a6c8-4d3d-a99e-c2aa1b02d84f', {'lang': 'py', 'task': 'celery_worker.tasks.new_game', 'id': 'cbc5c277-a6c8-4d3d-a99e-c2aa1b02d84f', 'shadow': None, 'eta': None, 'expires': None, 'group': None, 'retries': 0, 'timelimit': [None, None], 'root_id': 'cbc5c277-a6c8-4d3d-a99e-c2aa1b02d84f', 'parent_id': None, 'argsrepr': "('eziom', {'agents': {'human_agent': [...], 'solid_waste_aerobic_bioreactor': [...], 'multifiltration_purifier_post_treament': [...], 'oxygen_generation_SFWE': [...], 'urine_recycling_processor_VCD': [...], 'co2_removal_SAWD': [...], 'co2_reduction_sabatier': [...], 'crew_habitat_small': [...], 'greenhouse_small': [...], 'solar_pv_array_mars': [...], 'wheat': [...], 'cabbage': [...], 'strawberry': [...], 'radish': [...], 'red_beet': [...], 'lettuce': [...]}, 'storages': {'air_storage': [...], 'water_storage': [...], 'nutrient_storage': [...], 'power_storage': [...], 'food_storage': [...]}, 'termination': [{...}, {...}], 'single_agent': 1})", 'kwargsrepr':... kwargs:{})
celery-worker_2  | 2019-08-24T14:28:42.925176725Z [2019-08-24 14:28:42,924: DEBUG/MainProcess] Task accepted: celery_worker.tasks.new_game[cbc5c277-a6c8-4d3d-a99e-c2aa1b02d84f] pid:86
celery-worker_2  | 2019-08-24T14:28:44.868120483Z [2019-08-24 14:28:44,867: ERROR/ForkPoolWorker-16] Task celery_worker.tasks.new_game[cbc5c277-a6c8-4d3d-a99e-c2aa1b02d84f] raised unexpected: DetachedInstanceError('Instance <User at 0x7f8a197ed550> is not bound to a Session; attribute refresh operation cannot proceed',)
celery-worker_2  | 2019-08-24T14:28:44.868168234Z Traceback (most recent call last):
celery-worker_2  | 2019-08-24T14:28:44.868180042Z   File "/usr/local/lib/python3.6/dist-packages/celery/app/trace.py", line 385, in trace_task
celery-worker_2  | 2019-08-24T14:28:44.868191394Z     R = retval = fun(*args, **kwargs)
celery-worker_2  | 2019-08-24T14:28:44.868199021Z   File "/usr/local/lib/python3.6/dist-packages/celery/app/trace.py", line 648, in __protected_call__
celery-worker_2  | 2019-08-24T14:28:44.868209619Z     return self.run(*args, **kwargs)
celery-worker_2  | 2019-08-24T14:28:44.868218408Z   File "/simoc/celery_worker/tasks.py", line 66, in new_game
celery-worker_2  | 2019-08-24T14:28:44.868228220Z     game_runner_manager.new_game(user, game_runner_init_params)
celery-worker_2  | 2019-08-24T14:28:44.868236694Z   File "/simoc/simoc_server/game_runner.py", line 350, in new_game
celery-worker_2  | 2019-08-24T14:28:44.868245370Z     self._add_game_runner(user, game_runner)
celery-worker_2  | 2019-08-24T14:28:44.868283623Z   File "/simoc/simoc_server/game_runner.py", line 483, in _add_game_runner
celery-worker_2  | 2019-08-24T14:28:44.868294583Z     self.game_runners[user.id] = game_runner
celery-worker_2  | 2019-08-24T14:28:44.868302374Z   File "/usr/local/lib/python3.6/dist-packages/sqlalchemy/orm/attributes.py", line 282, in __get__
celery-worker_2  | 2019-08-24T14:28:44.868311568Z     return self.impl.get(instance_state(instance), dict_)
celery-worker_2  | 2019-08-24T14:28:44.868318376Z   File "/usr/local/lib/python3.6/dist-packages/sqlalchemy/orm/attributes.py", line 705, in get
celery-worker_2  | 2019-08-24T14:28:44.868327902Z     value = state._load_expired(state, passive)
celery-worker_2  | 2019-08-24T14:28:44.868335715Z   File "/usr/local/lib/python3.6/dist-packages/sqlalchemy/orm/state.py", line 660, in _load_expired
celery-worker_2  | 2019-08-24T14:28:44.868343845Z     self.manager.deferred_scalar_loader(self, toload)
celery-worker_2  | 2019-08-24T14:28:44.868351433Z   File "/usr/local/lib/python3.6/dist-packages/sqlalchemy/orm/loading.py", line 913, in load_scalar_attributes
celery-worker_2  | 2019-08-24T14:28:44.868358639Z     "attribute refresh operation cannot proceed" % (state_str(state))
celery-worker_2  | 2019-08-24T14:28:44.868368473Z sqlalchemy.orm.exc.DetachedInstanceError: Instance <User at 0x7f8a197ed550> is not bound to a Session; attribute refresh operation cannot proceed (Background on this error at: http://sqlalche.me/e/bhk3)
flask-app_1      | 2019-08-24T14:28:44.870712766Z Traceback (most recent call last):
flask-app_1      | 2019-08-24T14:28:44.870757093Z   File "/usr/local/lib/python3.6/dist-packages/flask/app.py", line 1612, in full_dispatch_request
flask-app_1      | 2019-08-24T14:28:44.870766985Z     rv = self.dispatch_request()
flask-app_1      | 2019-08-24T14:28:44.870775428Z   File "/usr/local/lib/python3.6/dist-packages/flask/app.py", line 1598, in dispatch_request
flask-app_1      | 2019-08-24T14:28:44.870782873Z     return self.view_functions[rule.endpoint](**req.view_args)
flask-app_1      | 2019-08-24T14:28:44.870790150Z   File "/usr/local/lib/python3.6/dist-packages/flask_login/utils.py", line 228, in decorated_view
flask-app_1      | 2019-08-24T14:28:44.870798114Z     return func(*args, **kwargs)
flask-app_1      | 2019-08-24T14:28:44.870806365Z   File "/simoc/simoc_server/views.py", line 118, in new_game
flask-app_1      | 2019-08-24T14:28:44.870814887Z     result = tasks.new_game.delay(get_standard_user_obj().username, game_config).get(timeout=60)
flask-app_1      | 2019-08-24T14:28:44.870824516Z   File "/usr/local/lib/python3.6/dist-packages/celery/result.py", line 226, in get
flask-app_1      | 2019-08-24T14:28:44.870855371Z     on_message=on_message,
flask-app_1      | 2019-08-24T14:28:44.870862474Z   File "/usr/local/lib/python3.6/dist-packages/celery/backends/asynchronous.py", line 190, in wait_for_pending
flask-app_1      | 2019-08-24T14:28:44.870869643Z     return result.maybe_throw(callback=callback, propagate=propagate)
flask-app_1      | 2019-08-24T14:28:44.870876337Z   File "/usr/local/lib/python3.6/dist-packages/celery/result.py", line 331, in maybe_throw
flask-app_1      | 2019-08-24T14:28:44.870884070Z     self.throw(value, self._to_remote_traceback(tb))
flask-app_1      | 2019-08-24T14:28:44.870891687Z   File "/usr/local/lib/python3.6/dist-packages/celery/result.py", line 324, in throw
flask-app_1      | 2019-08-24T14:28:44.870898478Z     self.on_ready.throw(*args, **kwargs)
flask-app_1      | 2019-08-24T14:28:44.870906101Z   File "/usr/local/lib/python3.6/dist-packages/vine/promises.py", line 244, in throw
flask-app_1      | 2019-08-24T14:28:44.870914282Z     reraise(type(exc), exc, tb)
flask-app_1      | 2019-08-24T14:28:44.870921069Z   File "/usr/local/lib/python3.6/dist-packages/vine/five.py", line 195, in reraise
flask-app_1      | 2019-08-24T14:28:44.870929911Z     raise value
flask-app_1      | 2019-08-24T14:28:44.870936598Z sqlalchemy.orm.exc.DetachedInstanceError: Instance <User at 0x7f8a197ed550> is not bound to a Session; attribute refresh operation cannot proceed (Background on this error at: http://sqlalche.me/e/bhk3)
flask-app_1      | 2019-08-24T14:28:44.870944535Z [2019-08-24 14:28:44 +0000] [9] [ERROR] ERROR: handling exception Instance <User at 0x7f8a197ed550> is not bound to a Session; attribute refresh operation cannot proceed (Background on this error at: http://sqlalche.me/e/bhk3)

I haven't figured out how to reproduce this reliably.

What I'm doing is:

  1. load hybrid4 preset from expert config
  2. change the duration to 100 hours
  3. click on [save] custom preset
  4. [load] the custom preset, and click on [finalize settings]
  5. if the Mission ID: field in the Mission Status has an ID go back to step 4 and retry, if the ID is missing you reproduced the bug
  6. if the ID is missing, the subsequent request to get_step_to will also fail, and the dashboard won't progress any further

cc: @Pebody

ezio-melotti commented 5 years ago

After the latest updates I see this almost every time while running locally. I can start the first sim with no problems, but when I try to start a new one (either by using the back button on the browser to go back to the config, doing "new simulation" from the dashboard menu, or logging off and doing everything from the beginning) and click on the "finalize settings" button, I get this error and I have to restart npm/vue before being able to run a new sim.

This is the server log:

flask-app_1      | 2019-10-01T05:27:12.881907190Z [2019-10-01 05:27:12 +0000] [10] [DEBUG] POST /new_game
celery-worker_2  | 2019-10-01T05:27:12.907526697Z [2019-10-01 05:27:12,907: INFO/MainProcess] Received task: celery_worker.tasks.new_game[6dc68f9e-816f-4610-909b-ba26cc0991a2]  
celery-worker_2  | 2019-10-01T05:27:12.907907803Z [2019-10-01 05:27:12,907: DEBUG/MainProcess] TaskPool: Apply <function _fast_trace_task at 0x7f8891e980d0> (args:('celery_worker.tasks.new_game', '6dc68f9e-816f-4610-909b-ba26cc0991a2', {'lang': 'py', 'task': 'celery_worker.tasks.new_game', 'id': '6dc68f9e-816f-4610-909b-ba26cc0991a2', 'shadow': None, 'eta': None, 'expires': None, 'group': None, 'retries': 0, 'timelimit': [None, None], 'root_id': '6dc68f9e-816f-4610-909b-ba26cc0991a2', 'parent_id': None, 'argsrepr': "('eziom', {'agents': {'human_agent': [...], 'solid_waste_aerobic_bioreactor': [...], 'multifiltration_purifier_post_treament': [...], 'oxygen_generation_SFWE': [...], 'urine_recycling_processor_VCD': [...], 'co2_removal_SAWD': [...], 'co2_reduction_sabatier': [...], 'crew_habitat_small': [...], 'greenhouse_small': [...], 'solar_pv_array_mars': [...], 'wheat': [...], 'cabbage': [...], 'strawberry': [...], 'radish': [...], 'red_beet': [...], 'lettuce': [...]}, 'storages': {'air_storage': [...], 'water_storage': [...], 'nutrient_storage': [...], 'power_storage': [...], 'food_storage': [...]}, 'termination': [{...}, {...}], 'single_agent': 1})", 'kwargsrepr':... kwargs:{})
celery-worker_2  | 2019-10-01T05:27:12.909913383Z [2019-10-01 05:27:12,909: DEBUG/MainProcess] Task accepted: celery_worker.tasks.new_game[6dc68f9e-816f-4610-909b-ba26cc0991a2] pid:14
flask-app_1      | 2019-10-01T05:27:15.112920209Z Traceback (most recent call last):
flask-app_1      | 2019-10-01T05:27:15.112973791Z   File "/usr/local/lib/python3.6/dist-packages/flask/app.py", line 1949, in full_dispatch_request
flask-app_1      | 2019-10-01T05:27:15.112983204Z     rv = self.dispatch_request()
flask-app_1      | 2019-10-01T05:27:15.112993041Z   File "/usr/local/lib/python3.6/dist-packages/flask/app.py", line 1935, in dispatch_request
flask-app_1      | 2019-10-01T05:27:15.113006525Z     return self.view_functions[rule.endpoint](**req.view_args)
flask-app_1      | 2019-10-01T05:27:15.113019172Z   File "/usr/local/lib/python3.6/dist-packages/flask_login/utils.py", line 261, in decorated_view
flask-app_1      | 2019-10-01T05:27:15.113032135Z     return func(*args, **kwargs)
flask-app_1      | 2019-10-01T05:27:15.113043290Z   File "/simoc/simoc_server/views.py", line 119, in new_game
flask-app_1      | 2019-10-01T05:27:15.113054203Z     result = tasks.new_game.delay(get_standard_user_obj().username, game_config).get(timeout=60)
flask-app_1      | 2019-10-01T05:27:15.113066601Z   File "/usr/local/lib/python3.6/dist-packages/celery/result.py", line 226, in get
flask-app_1      | 2019-10-01T05:27:15.113074465Z     on_message=on_message,
flask-app_1      | 2019-10-01T05:27:15.113081342Z   File "/usr/local/lib/python3.6/dist-packages/celery/backends/asynchronous.py", line 190, in wait_for_pending
flask-app_1      | 2019-10-01T05:27:15.113089316Z     return result.maybe_throw(callback=callback, propagate=propagate)
flask-app_1      | 2019-10-01T05:27:15.113096657Z   File "/usr/local/lib/python3.6/dist-packages/celery/result.py", line 331, in maybe_throw
flask-app_1      | 2019-10-01T05:27:15.113104201Z     self.throw(value, self._to_remote_traceback(tb))
flask-app_1      | 2019-10-01T05:27:15.113111495Z   File "/usr/local/lib/python3.6/dist-packages/celery/result.py", line 324, in throw
flask-app_1      | 2019-10-01T05:27:15.113123318Z     self.on_ready.throw(*args, **kwargs)
flask-app_1      | 2019-10-01T05:27:15.113135723Z   File "/usr/local/lib/python3.6/dist-packages/vine/promises.py", line 244, in throw
flask-app_1      | 2019-10-01T05:27:15.113147677Z     reraise(type(exc), exc, tb)
flask-app_1      | 2019-10-01T05:27:15.113159643Z   File "/usr/local/lib/python3.6/dist-packages/vine/five.py", line 195, in reraise
flask-app_1      | 2019-10-01T05:27:15.113171874Z     raise value
flask-app_1      | 2019-10-01T05:27:15.113183631Z sqlalchemy.orm.exc.DetachedInstanceError: Instance <User at 0x7f8890167f28> is not bound to a Session; attribute refresh operation cannot proceed (Background on this error at: http://sqlalche.me/e/bhk3)
flask-app_1      | 2019-10-01T05:27:15.113192151Z [2019-10-01 05:27:15 +0000] [10] [ERROR] ERROR: handling exception Instance <User at 0x7f8890167f28> is not bound to a Session; attribute refresh operation cannot proceed (Background on this error at: http://sqlalche.me/e/bhk3)
flask-app_1      | 2019-10-01T05:27:15.117901985Z [2019-10-01 05:27:15 +0000] [10] [DEBUG] Closing connection. 
celery-worker_2  | 2019-10-01T05:27:15.123568369Z [2019-10-01 05:27:15,122: ERROR/ForkPoolWorker-1] Task celery_worker.tasks.new_game[6dc68f9e-816f-4610-909b-ba26cc0991a2] raised unexpected: DetachedInstanceError('Instance <User at 0x7f8890167f28> is not bound to a Session; attribute refresh operation cannot proceed',)
celery-worker_2  | 2019-10-01T05:27:15.123616493Z Traceback (most recent call last):
celery-worker_2  | 2019-10-01T05:27:15.123625416Z   File "/usr/local/lib/python3.6/dist-packages/celery/app/trace.py", line 385, in trace_task
celery-worker_2  | 2019-10-01T05:27:15.123634214Z     R = retval = fun(*args, **kwargs)
celery-worker_2  | 2019-10-01T05:27:15.123641062Z   File "/usr/local/lib/python3.6/dist-packages/celery/app/trace.py", line 648, in __protected_call__
celery-worker_2  | 2019-10-01T05:27:15.123647603Z     return self.run(*args, **kwargs)
celery-worker_2  | 2019-10-01T05:27:15.123654528Z   File "/simoc/celery_worker/tasks.py", line 66, in new_game
celery-worker_2  | 2019-10-01T05:27:15.123661483Z     game_runner_manager.new_game(user, game_runner_init_params)
celery-worker_2  | 2019-10-01T05:27:15.123668285Z   File "/simoc/simoc_server/game_runner.py", line 350, in new_game
celery-worker_2  | 2019-10-01T05:27:15.123674830Z     self._add_game_runner(user, game_runner)
celery-worker_2  | 2019-10-01T05:27:15.123681331Z   File "/simoc/simoc_server/game_runner.py", line 483, in _add_game_runner
celery-worker_2  | 2019-10-01T05:27:15.123709832Z     self.game_runners[user.id] = game_runner
celery-worker_2  | 2019-10-01T05:27:15.123717450Z   File "/usr/local/lib/python3.6/dist-packages/sqlalchemy/orm/attributes.py", line 282, in __get__
celery-worker_2  | 2019-10-01T05:27:15.123723625Z     return self.impl.get(instance_state(instance), dict_)
celery-worker_2  | 2019-10-01T05:27:15.123729426Z   File "/usr/local/lib/python3.6/dist-packages/sqlalchemy/orm/attributes.py", line 705, in get
celery-worker_2  | 2019-10-01T05:27:15.123735213Z     value = state._load_expired(state, passive)
celery-worker_2  | 2019-10-01T05:27:15.123741096Z   File "/usr/local/lib/python3.6/dist-packages/sqlalchemy/orm/state.py", line 660, in _load_expired
celery-worker_2  | 2019-10-01T05:27:15.123747186Z     self.manager.deferred_scalar_loader(self, toload)
celery-worker_2  | 2019-10-01T05:27:15.123753087Z   File "/usr/local/lib/python3.6/dist-packages/sqlalchemy/orm/loading.py", line 913, in load_scalar_attributes
celery-worker_2  | 2019-10-01T05:27:15.123759840Z     "attribute refresh operation cannot proceed" % (state_str(state))
celery-worker_2  | 2019-10-01T05:27:15.123766167Z sqlalchemy.orm.exc.DetachedInstanceError: Instance <User at 0x7f8890167f28> is not bound to a Session; attribute refresh operation cannot proceed (Background on this error at: http://sqlalche.me/e/bhk3)

@iurii-milovanov can you look into this?